[ 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[1G[[32m ok [39;49m8[?25h[?0c.
[....] Starting OpenBSD Secure Shell server: sshd[?25l[?1c7[1G[[32m ok [39;49m8[?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] [<ffffffff86471cb1>] 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