[....] Starting enhanced syslogd: rsyslogd[?25l[?1c7[ ok 8[?25h[?0c. [ 80.228926][ T27] audit: type=1800 audit(1577928947.050:25): pid=8918 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="cron" dev="sda1" ino=2414 res=0 [ 80.264170][ T27] audit: type=1800 audit(1577928947.050:26): pid=8918 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="mcstrans" dev="sda1" ino=2457 res=0 [ 80.303853][ T27] audit: type=1800 audit(1577928947.050:27): pid=8918 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.0.182' (ECDSA) to the list of known hosts. 2020/01/02 01:35:57 parsed 1 programs 2020/01/02 01:35:59 executed programs: 0 syzkaller login: [ 92.348072][ T9087] IPVS: ftp: loaded support on port[0] = 21 [ 92.415964][ T9087] chnl_net:caif_netlink_parms(): no params data found [ 92.445788][ T9087] bridge0: port 1(bridge_slave_0) entered blocking state [ 92.453106][ T9087] bridge0: port 1(bridge_slave_0) entered disabled state [ 92.461902][ T9087] device bridge_slave_0 entered promiscuous mode [ 92.470002][ T9087] bridge0: port 2(bridge_slave_1) entered blocking state [ 92.477752][ T9087] bridge0: port 2(bridge_slave_1) entered disabled state [ 92.485476][ T9087] device bridge_slave_1 entered promiscuous mode [ 92.502212][ T9087] bond0: (slave bond_slave_0): Enslaving as an active interface with an up link [ 92.513413][ T9087] bond0: (slave bond_slave_1): Enslaving as an active interface with an up link [ 92.533700][ T9087] team0: Port device team_slave_0 added [ 92.541567][ T9087] team0: Port device team_slave_1 added [ 92.616701][ T9087] device hsr_slave_0 entered promiscuous mode [ 92.684332][ T9087] device hsr_slave_1 entered promiscuous mode [ 92.760792][ T9087] netdevsim netdevsim0 netdevsim0: renamed from eth0 [ 92.826715][ T9087] netdevsim netdevsim0 netdevsim1: renamed from eth1 [ 92.877235][ T9087] netdevsim netdevsim0 netdevsim2: renamed from eth2 [ 92.946108][ T9087] netdevsim netdevsim0 netdevsim3: renamed from eth3 [ 93.015045][ T9087] bridge0: port 2(bridge_slave_1) entered blocking state [ 93.022214][ T9087] bridge0: port 2(bridge_slave_1) entered forwarding state [ 93.029877][ T9087] bridge0: port 1(bridge_slave_0) entered blocking state [ 93.036964][ T9087] bridge0: port 1(bridge_slave_0) entered forwarding state [ 93.076190][ T9087] 8021q: adding VLAN 0 to HW filter on device bond0 [ 93.090394][ T2713] IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready [ 93.100440][ T2713] bridge0: port 1(bridge_slave_0) entered disabled state [ 93.108295][ T2713] bridge0: port 2(bridge_slave_1) entered disabled state [ 93.116226][ T2713] IPv6: ADDRCONF(NETDEV_CHANGE): bond0: link becomes ready [ 93.129371][ T9087] 8021q: adding VLAN 0 to HW filter on device team0 [ 93.139503][ T3146] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_0: link becomes ready [ 93.148445][ T3146] bridge0: port 1(bridge_slave_0) entered blocking state [ 93.155542][ T3146] bridge0: port 1(bridge_slave_0) entered forwarding state [ 93.166249][ T2713] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_1: link becomes ready [ 93.175062][ T2713] bridge0: port 2(bridge_slave_1) entered blocking state [ 93.182104][ T2713] bridge0: port 2(bridge_slave_1) entered forwarding state [ 93.205868][ T3146] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_0: link becomes ready [ 93.214879][ T3146] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_1: link becomes ready [ 93.223373][ T3146] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_0: link becomes ready [ 93.231977][ T3146] IPv6: ADDRCONF(NETDEV_CHANGE): team0: link becomes ready [ 93.243168][ T2713] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_1: link becomes ready [ 93.253439][ T9087] IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready [ 93.270032][ T3146] IPv6: ADDRCONF(NETDEV_CHANGE): vxcan0: link becomes ready [ 93.279111][ T3146] IPv6: ADDRCONF(NETDEV_CHANGE): vxcan1: link becomes ready [ 93.291571][ T9087] 8021q: adding VLAN 0 to HW filter on device batadv0 2020/01/02 01:36:04 executed programs: 100 2020/01/02 01:36:09 executed programs: 229 [ 102.572029][ T181] [ 102.574382][ T181] ===================================== [ 102.579945][ T181] WARNING: bad unlock balance detected! [ 102.585465][ T181] 5.5.0-rc4-syzkaller #0 Not tainted [ 102.590719][ T181] ------------------------------------- [ 102.596234][ T181] kworker/u4:3/181 is trying to release lock (&file->mut) at: [ 102.603676][ T181] [] ucma_event_handler+0x711/0xef0 [ 102.610414][ T181] but there are no more locks to release! [ 102.616102][ T181] [ 102.616102][ T181] other info that might help us debug this: [ 102.624138][ T181] 4 locks held by kworker/u4:3/181: [ 102.629306][ T181] #0: ffff88821aa9a928 ((wq_completion)ib_addr){+.+.}, at: process_one_work+0x88b/0x1740 [ 102.639183][ T181] #1: ffffc900016f7dc0 ((work_completion)(&(&req->work)->work)){+.+.}, at: process_one_work+0x8c1/0x1740 [ 102.650439][ T181] #2: ffff88809a021390 (&id_priv->handler_mutex){+.+.}, at: addr_handler+0xaf/0x3d0 [ 102.659872][ T181] #3: ffff8880a7302660 (&file->mut){+.+.}, at: ucma_event_handler+0xb3/0xef0 [ 102.668696][ T181] [ 102.668696][ T181] stack backtrace: [ 102.674569][ T181] CPU: 1 PID: 181 Comm: kworker/u4:3 Not tainted 5.5.0-rc4-syzkaller #0 [ 102.682873][ T181] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 102.692908][ T181] Workqueue: ib_addr process_one_req [ 102.698178][ T181] Call Trace: [ 102.701446][ T181] dump_stack+0x197/0x210 [ 102.705753][ T181] ? ucma_event_handler+0x711/0xef0 [ 102.710925][ T181] print_unlock_imbalance_bug.cold+0x114/0x123 [ 102.717059][ T181] ? ucma_event_handler+0x711/0xef0 [ 102.722232][ T181] lock_release+0x5f2/0x960 [ 102.726710][ T181] ? _raw_spin_unlock_irqrestore+0x66/0xe0 [ 102.732489][ T181] ? lock_downgrade+0x920/0x920 [ 102.737321][ T181] ? trace_hardirqs_on+0x67/0x240 [ 102.742324][ T181] ? _raw_spin_unlock_irqrestore+0x9f/0xe0 [ 102.748120][ T181] __mutex_unlock_slowpath+0x86/0x6a0 [ 102.753478][ T181] ? wait_for_completion+0x440/0x440 [ 102.758740][ T181] ? lockdep_hardirqs_on+0x421/0x5e0 [ 102.764003][ T181] mutex_unlock+0xd/0x10 [ 102.768224][ T181] ucma_event_handler+0x711/0xef0 [ 102.773225][ T181] addr_handler+0x2e9/0x3d0 [ 102.777704][ T181] ? cma_work_handler+0x1f0/0x1f0 [ 102.782743][ T181] ? __sanitizer_cov_trace_const_cmp1+0x1a/0x20 [ 102.788962][ T181] ? addr_resolve+0x3b0/0x1ad0 [ 102.793702][ T181] ? rdma_translate_ip+0x2f0/0x2f0 [ 102.798815][ T181] ? rcu_lockdep_current_cpu_online+0xe3/0x130 [ 102.804947][ T181] process_one_req+0x106/0x680 [ 102.809691][ T181] process_one_work+0x9af/0x1740 [ 102.814608][ T181] ? pwq_dec_nr_in_flight+0x320/0x320 [ 102.820412][ T181] ? lock_acquire+0x190/0x410 [ 102.825069][ T181] worker_thread+0x98/0xe40 [ 102.829560][ T181] kthread+0x361/0x430 [ 102.833608][ T181] ? process_one_work+0x1740/0x1740 [ 102.838779][ T181] ? kthread_mod_delayed_work+0x1f0/0x1f0 [ 102.844478][ T181] ret_from_fork+0x24/0x30