[ 91.245449][ T27] audit: type=1800 audit(1581144258.417:26): pid=9541 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="mcstrans" dev="sda1" ino=2457 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. [ 92.347148][ T27] kauditd_printk_skb: 2 callbacks suppressed [ 92.347159][ T27] audit: type=1800 audit(1581144259.527:29): pid=9541 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="rc.local" dev="sda1" ino=2432 res=0 [ 92.373791][ T27] audit: type=1800 audit(1581144259.537:30): pid=9541 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="rmnologin" dev="sda1" ino=2423 res=0 Debian GNU/Linux 7 syzkaller ttyS0 Warning: Permanently added '10.128.0.25' (ECDSA) to the list of known hosts. 2020/02/08 06:51:01 parsed 1 programs 2020/02/08 06:51:03 executed programs: 0 syzkaller login: [ 496.324597][ T9710] IPVS: ftp: loaded support on port[0] = 21 [ 496.396933][ T9710] chnl_net:caif_netlink_parms(): no params data found [ 496.443476][ T9710] bridge0: port 1(bridge_slave_0) entered blocking state [ 496.451288][ T9710] bridge0: port 1(bridge_slave_0) entered disabled state [ 496.460241][ T9710] device bridge_slave_0 entered promiscuous mode [ 496.469109][ T9710] bridge0: port 2(bridge_slave_1) entered blocking state [ 496.476235][ T9710] bridge0: port 2(bridge_slave_1) entered disabled state [ 496.484145][ T9710] device bridge_slave_1 entered promiscuous mode [ 496.501938][ T9710] bond0: (slave bond_slave_0): Enslaving as an active interface with an up link [ 496.512785][ T9710] bond0: (slave bond_slave_1): Enslaving as an active interface with an up link [ 496.534585][ T9710] team0: Port device team_slave_0 added [ 496.542321][ T9710] team0: Port device team_slave_1 added [ 496.557478][ T9710] batman_adv: batadv0: Adding interface: batadv_slave_0 [ 496.564645][ T9710] batman_adv: batadv0: The MTU of interface batadv_slave_0 is too small (1500) to handle the transport of batman-adv packets. Packets going over this interface will be fragmented on layer2 which could impact the performance. Setting the MTU to 1560 would solve the problem. [ 496.590607][ T9710] batman_adv: batadv0: Not using interface batadv_slave_0 (retrying later): interface not active [ 496.602917][ T9710] batman_adv: batadv0: Adding interface: batadv_slave_1 [ 496.610075][ T9710] batman_adv: batadv0: The MTU of interface batadv_slave_1 is too small (1500) to handle the transport of batman-adv packets. Packets going over this interface will be fragmented on layer2 which could impact the performance. Setting the MTU to 1560 would solve the problem. [ 496.636595][ T9710] batman_adv: batadv0: Not using interface batadv_slave_1 (retrying later): interface not active [ 496.691707][ T9710] device hsr_slave_0 entered promiscuous mode [ 496.759099][ T9710] device hsr_slave_1 entered promiscuous mode [ 496.873794][ T9710] netdevsim netdevsim0 netdevsim0: renamed from eth0 [ 496.933195][ T9710] netdevsim netdevsim0 netdevsim1: renamed from eth1 [ 497.001566][ T9710] netdevsim netdevsim0 netdevsim2: renamed from eth2 [ 497.040962][ T9710] netdevsim netdevsim0 netdevsim3: renamed from eth3 [ 497.102210][ T9710] bridge0: port 2(bridge_slave_1) entered blocking state [ 497.109608][ T9710] bridge0: port 2(bridge_slave_1) entered forwarding state [ 497.117348][ T9710] bridge0: port 1(bridge_slave_0) entered blocking state [ 497.124475][ T9710] bridge0: port 1(bridge_slave_0) entered forwarding state [ 497.168661][ T9710] 8021q: adding VLAN 0 to HW filter on device bond0 [ 497.182913][ T2989] IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready [ 497.194305][ T2989] bridge0: port 1(bridge_slave_0) entered disabled state [ 497.213545][ T2989] bridge0: port 2(bridge_slave_1) entered disabled state [ 497.222756][ T2989] IPv6: ADDRCONF(NETDEV_CHANGE): bond0: link becomes ready [ 497.235935][ T9710] 8021q: adding VLAN 0 to HW filter on device team0 [ 497.257994][ T2766] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_0: link becomes ready [ 497.266758][ T2766] bridge0: port 1(bridge_slave_0) entered blocking state [ 497.273985][ T2766] bridge0: port 1(bridge_slave_0) entered forwarding state [ 497.290321][ T2989] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_1: link becomes ready [ 497.298689][ T2989] bridge0: port 2(bridge_slave_1) entered blocking state [ 497.305794][ T2989] bridge0: port 2(bridge_slave_1) entered forwarding state [ 497.330127][ T2766] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_0: link becomes ready [ 497.340078][ T2766] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_1: link becomes ready [ 497.348517][ T2766] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_0: link becomes ready [ 497.357242][ T2766] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_1: link becomes ready [ 497.368057][ T2774] IPv6: ADDRCONF(NETDEV_CHANGE): team0: link becomes ready [ 497.377208][ T9710] IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready [ 497.396074][ T2989] IPv6: ADDRCONF(NETDEV_CHANGE): vxcan1: link becomes ready [ 497.404206][ T2989] IPv6: ADDRCONF(NETDEV_CHANGE): vxcan0: link becomes ready [ 497.416489][ T9710] 8021q: adding VLAN 0 to HW filter on device batadv0 [ 497.436805][ T2774] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_virt_wifi: link becomes ready [ 497.447726][ T2774] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_virt_wifi: link becomes ready [ 497.470257][ T2989] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_vlan: link becomes ready [ 497.479291][ T2989] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_vlan: link becomes ready [ 497.488414][ T2989] IPv6: ADDRCONF(NETDEV_CHANGE): vlan0: link becomes ready [ 497.497151][ T2989] IPv6: ADDRCONF(NETDEV_CHANGE): vlan1: link becomes ready [ 497.506683][ T9710] device veth0_vlan entered promiscuous mode [ 497.519219][ T9710] device veth1_vlan entered promiscuous mode [ 497.540368][ T2774] IPv6: ADDRCONF(NETDEV_CHANGE): macvlan0: link becomes ready [ 497.548411][ T2774] IPv6: ADDRCONF(NETDEV_CHANGE): macvlan1: link becomes ready [ 497.557194][ T2774] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_macvtap: link becomes ready [ 497.566126][ T2774] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_macvtap: link becomes ready [ 497.577364][ T9710] device veth0_macvtap entered promiscuous mode [ 497.587550][ T9710] device veth1_macvtap entered promiscuous mode [ 497.604916][ T9710] batman_adv: batadv0: Interface activated: batadv_slave_0 [ 497.612860][ T2989] IPv6: ADDRCONF(NETDEV_CHANGE): macvtap0: link becomes ready [ 497.621746][ T2989] IPv6: ADDRCONF(NETDEV_CHANGE): macsec0: link becomes ready [ 497.630041][ T2989] IPv6: ADDRCONF(NETDEV_CHANGE): batadv_slave_0: link becomes ready [ 497.638514][ T2989] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_batadv: link becomes ready [ 497.651245][ T9710] batman_adv: batadv0: Interface activated: batadv_slave_1 [ 497.659213][ T9720] IPv6: ADDRCONF(NETDEV_CHANGE): batadv_slave_1: link becomes ready [ 497.667749][ T9720] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_batadv: link becomes ready 2020/02/08 06:51:08 executed programs: 143 2020/02/08 06:51:13 executed programs: 357 2020/02/08 06:51:18 executed programs: 580 2020/02/08 06:51:23 executed programs: 800 2020/02/08 06:51:28 executed programs: 1021 2020/02/08 06:51:33 executed programs: 1238 2020/02/08 06:51:38 executed programs: 1455 2020/02/08 06:51:43 executed programs: 1672 2020/02/08 06:51:48 executed programs: 1896 2020/02/08 06:51:53 executed programs: 2119 2020/02/08 06:51:58 executed programs: 2343 2020/02/08 06:52:03 executed programs: 2564 2020/02/08 06:52:08 executed programs: 2787 2020/02/08 06:52:13 executed programs: 3009 2020/02/08 06:52:18 executed programs: 3230 2020/02/08 06:52:23 executed programs: 3449 2020/02/08 06:52:28 executed programs: 3665 2020/02/08 06:52:33 executed programs: 3878 2020/02/08 06:52:38 executed programs: 4094 2020/02/08 06:52:43 executed programs: 4309 2020/02/08 06:52:48 executed programs: 4522 2020/02/08 06:52:53 executed programs: 4739 2020/02/08 06:52:58 executed programs: 4951 2020/02/08 06:53:03 executed programs: 5169 2020/02/08 06:53:08 executed programs: 5387 2020/02/08 06:53:13 executed programs: 5601 2020/02/08 06:53:18 executed programs: 5818 2020/02/08 06:53:23 executed programs: 6034 2020/02/08 06:53:28 executed programs: 6248 2020/02/08 06:53:33 executed programs: 6455 2020/02/08 06:53:38 executed programs: 6664 2020/02/08 06:53:43 executed programs: 6873 2020/02/08 06:53:48 executed programs: 7083 2020/02/08 06:53:53 executed programs: 7301 2020/02/08 06:53:58 executed programs: 7518 2020/02/08 06:54:03 executed programs: 7726 2020/02/08 06:54:08 executed programs: 7931 2020/02/08 06:54:13 executed programs: 8137 2020/02/08 06:54:18 executed programs: 8344 2020/02/08 06:54:23 executed programs: 8552 2020/02/08 06:54:28 executed programs: 8768 2020/02/08 06:54:33 executed programs: 8979 2020/02/08 06:54:39 executed programs: 9186 2020/02/08 06:54:44 executed programs: 9387 2020/02/08 06:54:49 executed programs: 9590 2020/02/08 06:54:54 executed programs: 9796 2020/02/08 06:54:59 executed programs: 10020 2020/02/08 06:55:04 executed programs: 10241 2020/02/08 06:55:09 executed programs: 10466 2020/02/08 06:55:14 executed programs: 10684 2020/02/08 06:55:19 executed programs: 10888 2020/02/08 06:55:24 executed programs: 11087 2020/02/08 06:55:29 executed programs: 11289 2020/02/08 06:55:34 executed programs: 11499 2020/02/08 06:55:39 executed programs: 11714 [ 774.521809][ T9717] BUG: sleeping function called from invalid context at net/core/sock.c:2935 [ 774.531731][ T9717] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 9717, name: kworker/0:1 [ 774.541194][ T9717] 4 locks held by kworker/0:1/9717: [ 774.546505][ T9717] #0: ffff8880aa426d28 ((wq_completion)events){+.+.}, at: process_one_work+0x8dd/0x17a0 [ 774.557281][ T9717] #1: ffffc90002367dc0 ((work_completion)(&map->work)){+.+.}, at: process_one_work+0x917/0x17a0 [ 774.568296][ T9717] #2: ffffffff89babb80 (rcu_read_lock){....}, at: sock_hash_free+0x0/0x540 [ 774.577660][ T9717] #3: ffffc900049bd2e0 (&htab->buckets[i].lock){+...}, at: sock_hash_free+0x131/0x540 [ 774.587584][ T9717] Preemption disabled at: [ 774.587608][ T9717] [] sock_hash_free+0x131/0x540 [ 774.598790][ T9717] CPU: 0 PID: 9717 Comm: kworker/0:1 Not tainted 5.5.0-syzkaller #0 [ 774.607187][ T9717] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 774.617767][ T9717] Workqueue: events bpf_map_free_deferred [ 774.623809][ T9717] Call Trace: [ 774.627439][ T9717] dump_stack+0x197/0x210 [ 774.631970][ T9717] ? sock_hash_free+0x131/0x540 [ 774.637051][ T9717] ___might_sleep.cold+0x1fb/0x23e [ 774.642304][ T9717] __might_sleep+0x95/0x190 [ 774.646916][ T9717] lock_sock_nested+0x39/0x120 [ 774.652205][ T9717] sock_hash_free+0x29f/0x540 [ 774.657159][ T9717] bpf_map_free_deferred+0xb3/0x100 [ 774.662581][ T9717] ? bpf_map_charge_move+0x80/0x80 [ 774.668236][ T9717] ? trace_hardirqs_on+0x67/0x240 [ 774.673584][ T9717] process_one_work+0xa05/0x17a0 [ 774.678734][ T9717] ? mark_held_locks+0xf0/0xf0 [ 774.683725][ T9717] ? pwq_dec_nr_in_flight+0x320/0x320 [ 774.689109][ T9717] ? lock_acquire+0x190/0x410 [ 774.694096][ T9717] worker_thread+0x98/0xe40 [ 774.699690][ T9717] ? trace_hardirqs_on+0x67/0x240 [ 774.705314][ T9717] kthread+0x361/0x430 [ 774.709682][ T9717] ? process_one_work+0x17a0/0x17a0 [ 774.715133][ T9717] ? kthread_mod_delayed_work+0x1f0/0x1f0 [ 774.721276][ T9717] ret_from_fork+0x24/0x30 [ 774.726103][ T9717] [ 774.728609][ T9717] ====================================================== [ 774.735871][ T9717] WARNING: possible circular locking dependency detected [ 774.742894][ T9717] 5.5.0-syzkaller #0 Tainted: G W [ 774.749302][ T9717] ------------------------------------------------------ [ 774.756523][ T9717] kworker/0:1/9717 is trying to acquire lock: [ 774.762785][ T9717] ffff888096d5a290 (sk_lock-AF_INET6){+.+.}, at: sock_hash_free+0x29f/0x540 [ 774.771766][ T9717] [ 774.771766][ T9717] but task is already holding lock: [ 774.779330][ T9717] ffffc900049bd2e0 (&htab->buckets[i].lock){+...}, at: sock_hash_free+0x131/0x540 [ 774.789508][ T9717] [ 774.789508][ T9717] which lock already depends on the new lock. [ 774.789508][ T9717] [ 774.800380][ T9717] [ 774.800380][ T9717] the existing dependency chain (in reverse order) is: [ 774.809940][ T9717] [ 774.809940][ T9717] -> #1 (&htab->buckets[i].lock){+...}: [ 774.817775][ T9717] _raw_spin_lock_bh+0x33/0x50 [ 774.823229][ T9717] sock_hash_update_common+0x810/0x1050 [ 774.829776][ T9717] sock_hash_update_elem+0x242/0x2b0 [ 774.835678][ T9717] bpf_map_update_value.isra.0+0x2a6/0x8e0 [ 774.842217][ T9717] __do_sys_bpf+0x3163/0x41e0 [ 774.847537][ T9717] __x64_sys_bpf+0x73/0xb0 [ 774.852760][ T9717] do_syscall_64+0xfa/0x790 [ 774.857989][ T9717] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 774.864726][ T9717] [ 774.864726][ T9717] -> #0 (sk_lock-AF_INET6){+.+.}: [ 774.872205][ T9717] __lock_acquire+0x2596/0x4a00 [ 774.877767][ T9717] lock_acquire+0x190/0x410 [ 774.883027][ T9717] lock_sock_nested+0xcb/0x120 [ 774.888513][ T9717] sock_hash_free+0x29f/0x540 [ 774.893924][ T9717] bpf_map_free_deferred+0xb3/0x100 [ 774.899835][ T9717] process_one_work+0xa05/0x17a0 [ 774.905393][ T9717] worker_thread+0x98/0xe40 [ 774.910706][ T9717] kthread+0x361/0x430 [ 774.915299][ T9717] ret_from_fork+0x24/0x30 [ 774.920519][ T9717] [ 774.920519][ T9717] other info that might help us debug this: [ 774.920519][ T9717] [ 774.930916][ T9717] Possible unsafe locking scenario: [ 774.930916][ T9717] [ 774.938821][ T9717] CPU0 CPU1 [ 774.944202][ T9717] ---- ---- [ 774.949789][ T9717] lock(&htab->buckets[i].lock); [ 774.954981][ T9717] lock(sk_lock-AF_INET6); [ 774.962391][ T9717] lock(&htab->buckets[i].lock); [ 774.970222][ T9717] lock(sk_lock-AF_INET6); [ 774.975200][ T9717] [ 774.975200][ T9717] *** DEADLOCK *** [ 774.975200][ T9717] [ 774.984996][ T9717] 4 locks held by kworker/0:1/9717: [ 774.990187][ T9717] #0: ffff8880aa426d28 ((wq_completion)events){+.+.}, at: process_one_work+0x8dd/0x17a0 [ 775.000475][ T9717] #1: ffffc90002367dc0 ((work_completion)(&map->work)){+.+.}, at: process_one_work+0x917/0x17a0 [ 775.011160][ T9717] #2: ffffffff89babb80 (rcu_read_lock){....}, at: sock_hash_free+0x0/0x540 [ 775.020145][ T9717] #3: ffffc900049bd2e0 (&htab->buckets[i].lock){+...}, at: sock_hash_free+0x131/0x540 [ 775.030545][ T9717] [ 775.030545][ T9717] stack backtrace: [ 775.036603][ T9717] CPU: 0 PID: 9717 Comm: kworker/0:1 Tainted: G W 5.5.0-syzkaller #0 [ 775.046517][ T9717] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 775.056837][ T9717] Workqueue: events bpf_map_free_deferred [ 775.063043][ T9717] Call Trace: [ 775.066709][ T9717] dump_stack+0x197/0x210 [ 775.071039][ T9717] print_circular_bug.isra.0.cold+0x163/0x172 [ 775.077262][ T9717] check_noncircular+0x32e/0x3e0 [ 775.082203][ T9717] ? print_circular_bug.isra.0+0x230/0x230 [ 775.088178][ T9717] ? mark_held_locks+0xa4/0xf0 [ 775.093185][ T9717] ? alloc_list_entry+0xc0/0xc0 [ 775.098150][ T9717] ? __sanitizer_cov_trace_const_cmp8+0x18/0x20 [ 775.105168][ T9717] ? find_first_zero_bit+0x9a/0xc0 [ 775.110703][ T9717] __lock_acquire+0x2596/0x4a00 [ 775.115559][ T9717] ? mark_held_locks+0xf0/0xf0 [ 775.120598][ T9717] lock_acquire+0x190/0x410 [ 775.125846][ T9717] ? sock_hash_free+0x29f/0x540 [ 775.130738][ T9717] lock_sock_nested+0xcb/0x120 [ 775.135675][ T9717] ? sock_hash_free+0x29f/0x540 [ 775.140903][ T9717] sock_hash_free+0x29f/0x540 [ 775.145583][ T9717] bpf_map_free_deferred+0xb3/0x100 [ 775.151556][ T9717] ? bpf_map_charge_move+0x80/0x80 [ 775.156919][ T9717] ? trace_hardirqs_on+0x67/0x240 [ 775.162568][ T9717] process_one_work+0xa05/0x17a0 [ 775.167555][ T9717] ? mark_held_locks+0xf0/0xf0 [ 775.172422][ T9717] ? pwq_dec_nr_in_flight+0x320/0x320 [ 775.177812][ T9717] ? lock_acquire+0x190/0x410 [ 775.182922][ T9717] worker_thread+0x98/0xe40 [ 775.187683][ T9717] ? trace_hardirqs_on+0x67/0x240 [ 775.192927][ T9717] kthread+0x361/0x430 [ 775.197048][ T9717] ? process_one_work+0x17a0/0x17a0 [ 775.202467][ T9717] ? kthread_mod_delayed_work+0x1f0/0x1f0 [ 775.208250][ T9717] ret_from_fork+0x24/0x30 2020/02/08 06:55:44 executed programs: 11926 2020/02/08 06:55:49 executed programs: 12222