[ 427.570679][ T4379] Bluetooth: hci0: unexpected event 0x40 length: 31 > 2 [ 428.387415][ T4379] Bluetooth: hci0: unexpected event 0x40 length: 31 > 2 [ 429.211460][ T4379] Bluetooth: hci0: unexpected event 0x40 length: 31 > 2 [ 430.026405][ T4379] Bluetooth: hci0: unexpected event 0x40 length: 31 > 2 [ 430.856667][ T4379] Bluetooth: hci0: unexpected event 0x40 length: 31 > 2 [ 431.680699][ T4379] Bluetooth: hci0: unexpected event 0x40 length: 31 > 2 [ 432.496147][ T4379] Bluetooth: hci0: unexpected event 0x40 length: 31 > 2 [ 433.318296][ T4379] Bluetooth: hci0: unexpected event 0x40 length: 31 > 2 [ 434.134710][ T4379] Bluetooth: hci0: unexpected event 0x40 length: 31 > 2 [ 434.960450][ T4379] Bluetooth: hci0: unexpected event 0x40 length: 31 > 2 [ 435.780239][ T4379] Bluetooth: hci0: unexpected event 0x40 length: 31 > 2 [ 436.601032][ T4379] Bluetooth: hci0: unexpected event 0x40 length: 31 > 2 [ 437.699385][ T71] netdevsim netdevsim0 netdevsim3 (unregistering): unset [1, 0] type 2 family 0 port 6081 - 0 [ 437.792527][ T71] netdevsim netdevsim0 netdevsim2 (unregistering): unset [1, 0] type 2 family 0 port 6081 - 0 [ 437.845948][ T71] netdevsim netdevsim0 netdevsim1 (unregistering): unset [1, 0] type 2 family 0 port 6081 - 0 [ 437.915533][ T71] netdevsim netdevsim0 netdevsim0 (unregistering): unset [1, 0] type 2 family 0 port 6081 - 0 [ 438.033659][ T26] kauditd_printk_skb: 1 callbacks suppressed [ 438.033676][ T26] audit: type=1400 audit(1672632207.384:179): avc: denied { read } for pid=4634 comm="dhcpcd" scontext=system_u:system_r:dhcpc_t tcontext=system_u:system_r:dhcpc_t tclass=netlink_kobject_uevent_socket permissive=1 [ 438.115140][ T26] audit: type=1400 audit(1672632207.414:180): avc: denied { search } for pid=4634 comm="dhcpcd" name="/" dev="tmpfs" ino=1 scontext=system_u:system_r:dhcpc_t tcontext=system_u:object_r:tmpfs_t tclass=dir permissive=1 [ 438.193310][ T26] audit: type=1400 audit(1672632207.544:181): avc: denied { read } for pid=6054 comm="dhcpcd-run-hook" name="resolv.conf" dev="tmpfs" ino=1405 scontext=system_u:system_r:dhcpc_t tcontext=system_u:object_r:tmpfs_t tclass=dir permissive=1 [ 438.216709][ T26] audit: type=1400 audit(1672632207.544:182): avc: denied { open } for pid=6054 comm="dhcpcd-run-hook" path="/run/dhcpcd/hook-state/resolv.conf" dev="tmpfs" ino=1405 scontext=system_u:system_r:dhcpc_t tcontext=system_u:object_r:tmpfs_t tclass=dir permissive=1 [ 438.242533][ T26] audit: type=1400 audit(1672632207.544:183): avc: denied { getattr } for pid=6054 comm="dhcpcd-run-hook" path="/run/dhcpcd/hook-state/resolv.conf" dev="tmpfs" ino=1405 scontext=system_u:system_r:dhcpc_t tcontext=system_u:object_r:tmpfs_t tclass=dir permissive=1 [ 438.376051][ T26] audit: type=1400 audit(1672632207.724:184): avc: denied { write } for pid=6053 comm="dhcpcd-run-hook" name="hook-state" dev="tmpfs" ino=1404 scontext=system_u:system_r:dhcpc_t tcontext=system_u:object_r:tmpfs_t tclass=dir permissive=1 [ 438.399533][ T26] audit: type=1400 audit(1672632207.724:185): avc: denied { add_name } for pid=6053 comm="dhcpcd-run-hook" name="resolv.conf.eth1.link" scontext=system_u:system_r:dhcpc_t tcontext=system_u:object_r:tmpfs_t tclass=dir permissive=1 [ 438.453926][ T26] audit: type=1400 audit(1672632207.804:186): avc: denied { remove_name } for pid=6064 comm="rm" name="resolv.conf.eth1.link" dev="tmpfs" ino=3249 scontext=system_u:system_r:dhcpc_t tcontext=system_u:object_r:tmpfs_t tclass=dir permissive=1 [ 438.732463][ T71] device hsr_slave_0 left promiscuous mode [ 438.740416][ T71] device hsr_slave_1 left promiscuous mode [ 438.747192][ T71] batman_adv: batadv0: Interface deactivated: batadv_slave_0 [ 438.754626][ T71] batman_adv: batadv0: Removing interface: batadv_slave_0 [ 438.763863][ T71] batman_adv: batadv0: Interface deactivated: batadv_slave_1 [ 438.771321][ T71] batman_adv: batadv0: Removing interface: batadv_slave_1 [ 438.780068][ T71] device bridge_slave_1 left promiscuous mode [ 438.787253][ T71] bridge0: port 2(bridge_slave_1) entered disabled state [ 438.796623][ T71] device bridge_slave_0 left promiscuous mode [ 438.802947][ T71] bridge0: port 1(bridge_slave_0) entered disabled state [ 438.815121][ T71] device veth1_macvtap left promiscuous mode [ 438.821450][ T71] device veth0_macvtap left promiscuous mode [ 438.827620][ T71] device veth1_vlan left promiscuous mode [ 438.834130][ T71] device veth0_vlan left promiscuous mode [ 438.969800][ T71] team0 (unregistering): Port device team_slave_1 removed [ 438.982635][ T71] team0 (unregistering): Port device team_slave_0 removed [ 438.994763][ T71] bond0 (unregistering): (slave bond_slave_1): Releasing backup interface [ 439.009091][ T71] bond0 (unregistering): (slave bond_slave_0): Releasing backup interface [ 439.058810][ T71] bond0 (unregistering): Released all slaves Warning: Permanently added '10.128.10.56' (ECDSA) to the list of known hosts. [ 441.740890][ T26] audit: type=1400 audit(1672632211.094:187): avc: denied { transition } for pid=6170 comm="sshd" path="/bin/sh" dev="sda1" ino=73 scontext=system_u:system_r:initrc_t tcontext=root:sysadm_r:sysadm_t tclass=process permissive=1 [ 441.955917][ T6176] chnl_net:caif_netlink_parms(): no params data found [ 442.024673][ T6176] bridge0: port 1(bridge_slave_0) entered blocking state [ 442.033366][ T6176] bridge0: port 1(bridge_slave_0) entered disabled state [ 442.041861][ T6176] device bridge_slave_0 entered promiscuous mode [ 442.052159][ T6176] bridge0: port 2(bridge_slave_1) entered blocking state [ 442.059567][ T6176] bridge0: port 2(bridge_slave_1) entered disabled state [ 442.069243][ T6176] device bridge_slave_1 entered promiscuous mode [ 442.101732][ T6176] bond0: (slave bond_slave_0): Enslaving as an active interface with an up link [ 442.116007][ T6176] bond0: (slave bond_slave_1): Enslaving as an active interface with an up link [ 442.153341][ T6176] team0: Port device team_slave_0 added [ 442.161980][ T6176] team0: Port device team_slave_1 added [ 442.190315][ T6176] batman_adv: batadv0: Adding interface: batadv_slave_0 [ 442.197655][ T6176] 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. [ 442.225979][ T6176] batman_adv: batadv0: Not using interface batadv_slave_0 (retrying later): interface not active [ 442.241132][ T6176] batman_adv: batadv0: Adding interface: batadv_slave_1 [ 442.248270][ T6176] 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. [ 442.275680][ T6176] batman_adv: batadv0: Not using interface batadv_slave_1 (retrying later): interface not active [ 442.316134][ T6176] device hsr_slave_0 entered promiscuous mode [ 442.323323][ T6176] device hsr_slave_1 entered promiscuous mode [ 442.438106][ T6176] bridge0: port 2(bridge_slave_1) entered blocking state [ 442.445285][ T6176] bridge0: port 2(bridge_slave_1) entered forwarding state [ 442.452640][ T6176] bridge0: port 1(bridge_slave_0) entered blocking state [ 442.459930][ T6176] bridge0: port 1(bridge_slave_0) entered forwarding state [ 442.535569][ T6176] 8021q: adding VLAN 0 to HW filter on device bond0 [ 442.551511][ T21] IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready [ 442.562548][ T21] bridge0: port 1(bridge_slave_0) entered disabled state [ 442.572541][ T21] bridge0: port 2(bridge_slave_1) entered disabled state [ 442.581361][ T21] IPv6: ADDRCONF(NETDEV_CHANGE): bond0: link becomes ready [ 442.596029][ T6176] 8021q: adding VLAN 0 to HW filter on device team0 [ 442.609948][ T5066] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_0: link becomes ready [ 442.619346][ T5066] bridge0: port 1(bridge_slave_0) entered blocking state [ 442.626537][ T5066] bridge0: port 1(bridge_slave_0) entered forwarding state [ 442.648951][ T5066] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_1: link becomes ready [ 442.657952][ T5066] bridge0: port 2(bridge_slave_1) entered blocking state [ 442.665081][ T5066] bridge0: port 2(bridge_slave_1) entered forwarding state [ 442.695108][ T6052] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_0: link becomes ready [ 442.708199][ T6052] IPv6: ADDRCONF(NETDEV_CHANGE): team0: link becomes ready [ 442.717295][ T6052] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_1: link becomes ready [ 442.730412][ T6176] IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready [ 442.750637][ T21] IPv6: ADDRCONF(NETDEV_CHANGE): vxcan0: link becomes ready [ 442.759107][ T21] IPv6: ADDRCONF(NETDEV_CHANGE): vxcan1: link becomes ready [ 442.772461][ T6176] 8021q: adding VLAN 0 to HW filter on device batadv0 [ 443.418208][ T5066] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_virt_wifi: link becomes ready [ 443.429177][ T5066] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_virt_wifi: link becomes ready [ 443.453062][ T5066] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_vlan: link becomes ready [ 443.462490][ T5066] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_vlan: link becomes ready [ 443.474938][ T6176] device veth0_vlan entered promiscuous mode [ 443.483754][ T6052] IPv6: ADDRCONF(NETDEV_CHANGE): vlan0: link becomes ready [ 443.494497][ T6052] IPv6: ADDRCONF(NETDEV_CHANGE): vlan1: link becomes ready [ 443.509555][ T6176] device veth1_vlan entered promiscuous mode [ 443.536644][ T6052] IPv6: ADDRCONF(NETDEV_CHANGE): macvlan0: link becomes ready [ 443.545469][ T6052] IPv6: ADDRCONF(NETDEV_CHANGE): macvlan1: link becomes ready [ 443.556238][ T6052] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_macvtap: link becomes ready [ 443.565372][ T6052] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_macvtap: link becomes ready [ 443.579352][ T6176] device veth0_macvtap entered promiscuous mode [ 443.594798][ T6176] device veth1_macvtap entered promiscuous mode [ 443.618365][ T6176] batman_adv: batadv0: Interface activated: batadv_slave_0 [ 443.625733][ T6052] IPv6: ADDRCONF(NETDEV_CHANGE): macvtap0: link becomes ready [ 443.636505][ T6052] IPv6: ADDRCONF(NETDEV_CHANGE): macsec0: link becomes ready [ 443.644727][ T6052] IPv6: ADDRCONF(NETDEV_CHANGE): batadv_slave_0: link becomes ready [ 443.655767][ T6052] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_batadv: link becomes ready [ 443.670608][ T6176] batman_adv: batadv0: Interface activated: batadv_slave_1 [ 443.682471][ T5066] IPv6: ADDRCONF(NETDEV_CHANGE): batadv_slave_1: link becomes ready [ 443.692189][ T5066] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_batadv: link becomes ready [ 444.774842][ T5147] Bluetooth: hci0: unexpected cc 0x0c03 length: 249 > 1 [ 444.783159][ T5147] Bluetooth: hci0: unexpected cc 0x1003 length: 249 > 9 [ 444.791125][ T5147] Bluetooth: hci0: unexpected cc 0x1001 length: 249 > 9 [ 444.799355][ T5147] Bluetooth: hci0: unexpected cc 0x0c23 length: 249 > 4 [ 444.807206][ T5147] Bluetooth: hci0: unexpected cc 0x0c25 length: 249 > 3 [ 444.814480][ T5147] Bluetooth: hci0: unexpected cc 0x0c38 length: 249 > 2 [ 444.829769][ T5147] Bluetooth: hci0: unexpected event 0x40 length: 31 > 2 [ 446.846696][ T5147] Bluetooth: hci0: command 0x0409 tx timeout [ 448.936639][ T5147] Bluetooth: hci0: command 0x041b tx timeout [ 451.006775][ T5147] Bluetooth: hci0: command 0x040f tx timeout [ 453.086842][ T5147] Bluetooth: hci0: command 0x0405 tx timeout [ 455.167383][ T5147] Bluetooth: hci0: command 0x0419 tx timeout [ 485.258309][ T21] [ 485.260662][ T21] ====================================================== [ 485.267669][ T21] WARNING: possible circular locking dependency detected [ 485.275360][ T21] 6.2.0-rc2-syzkaller-00117-g88603b6dc419 #0 Not tainted [ 485.282357][ T21] ------------------------------------------------------ [ 485.289351][ T21] kworker/1:0/21 is trying to acquire lock: [ 485.295217][ T21] ffff88802b9c0130 (sk_lock-AF_BLUETOOTH-BTPROTO_SCO){+.+.}-{0:0}, at: sco_sock_timeout+0xd1/0x290 [ 485.305966][ T21] [ 485.305966][ T21] but task is already holding lock: [ 485.313310][ T21] ffffc900003cfda8 ((work_completion)(&(&conn->timeout_work)->work)){+.+.}-{0:0}, at: process_one_work+0x8a1/0x1710 [ 485.325493][ T21] [ 485.325493][ T21] which lock already depends on the new lock. [ 485.325493][ T21] [ 485.335874][ T21] [ 485.335874][ T21] the existing dependency chain (in reverse order) is: [ 485.344871][ T21] [ 485.344871][ T21] -> #3 ((work_completion)(&(&conn->timeout_work)->work)){+.+.}-{0:0}: [ 485.355294][ T21] __flush_work+0x109/0xaf0 [ 485.360324][ T21] __cancel_work_timer+0x3f9/0x570 [ 485.365978][ T21] sco_conn_del+0x1b5/0x2b0 [ 485.371012][ T21] sco_disconn_cfm+0x75/0xb0 [ 485.376131][ T21] hci_conn_hash_flush+0x126/0x260 [ 485.381870][ T21] hci_dev_close_sync+0x5fb/0x1200 [ 485.387569][ T21] hci_dev_do_close+0x31/0x70 [ 485.392777][ T21] hci_unregister_dev+0x1ce/0x580 [ 485.398330][ T21] vhci_release+0x80/0xf0 [ 485.403257][ T21] __fput+0x27c/0xa90 [ 485.407793][ T21] task_work_run+0x16f/0x270 [ 485.412909][ T21] do_exit+0xaa8/0x2950 [ 485.417585][ T21] do_group_exit+0xd4/0x2a0 [ 485.422612][ T21] get_signal+0x21c3/0x2450 [ 485.427645][ T21] arch_do_signal_or_restart+0x79/0x5c0 [ 485.433708][ T21] exit_to_user_mode_prepare+0x15f/0x250 [ 485.439908][ T21] syscall_exit_to_user_mode+0x1d/0x50 [ 485.446015][ T21] do_syscall_64+0x46/0xb0 [ 485.450967][ T21] entry_SYSCALL_64_after_hwframe+0x63/0xcd [ 485.457504][ T21] [ 485.457504][ T21] -> #2 (hci_cb_list_lock){+.+.}-{3:3}: [ 485.465233][ T21] __mutex_lock+0x12f/0x1360 [ 485.470380][ T21] hci_remote_features_evt+0x49e/0xa20 [ 485.476369][ T21] hci_event_packet+0x956/0xfd0 [ 485.481735][ T21] hci_rx_work+0xaeb/0x1230 [ 485.486760][ T21] process_one_work+0x9bf/0x1710 [ 485.492214][ T21] worker_thread+0x669/0x1090 [ 485.497406][ T21] kthread+0x2e8/0x3a0 [ 485.501990][ T21] ret_from_fork+0x1f/0x30 [ 485.507017][ T21] [ 485.507017][ T21] -> #1 (&hdev->lock){+.+.}-{3:3}: [ 485.514309][ T21] __mutex_lock+0x12f/0x1360 [ 485.519417][ T21] sco_sock_connect+0x1ea/0xa60 [ 485.524782][ T21] __sys_connect_file+0x153/0x1a0 [ 485.530376][ T21] __sys_connect+0x165/0x1a0 [ 485.535480][ T21] __x64_sys_connect+0x73/0xb0 [ 485.540756][ T21] do_syscall_64+0x39/0xb0 [ 485.545701][ T21] entry_SYSCALL_64_after_hwframe+0x63/0xcd [ 485.552115][ T21] [ 485.552115][ T21] -> #0 (sk_lock-AF_BLUETOOTH-BTPROTO_SCO){+.+.}-{0:0}: [ 485.561236][ T21] __lock_acquire+0x2a43/0x56d0 [ 485.566706][ T21] lock_acquire+0x1e3/0x630 [ 485.571736][ T21] lock_sock_nested+0x3a/0xf0 [ 485.577023][ T21] sco_sock_timeout+0xd1/0x290 [ 485.582304][ T21] process_one_work+0x9bf/0x1710 [ 485.587762][ T21] worker_thread+0x669/0x1090 [ 485.592975][ T21] kthread+0x2e8/0x3a0 [ 485.597560][ T21] ret_from_fork+0x1f/0x30 [ 485.602500][ T21] [ 485.602500][ T21] other info that might help us debug this: [ 485.602500][ T21] [ 485.612805][ T21] Chain exists of: [ 485.612805][ T21] sk_lock-AF_BLUETOOTH-BTPROTO_SCO --> hci_cb_list_lock --> (work_completion)(&(&conn->timeout_work)->work) [ 485.612805][ T21] [ 485.630197][ T21] Possible unsafe locking scenario: [ 485.630197][ T21] [ 485.637638][ T21] CPU0 CPU1 [ 485.642993][ T21] ---- ---- [ 485.648349][ T21] lock((work_completion)(&(&conn->timeout_work)->work)); [ 485.655538][ T21] lock(hci_cb_list_lock); [ 485.662556][ T21] lock((work_completion)(&(&conn->timeout_work)->work)); [ 485.672263][ T21] lock(sk_lock-AF_BLUETOOTH-BTPROTO_SCO); [ 485.678150][ T21] [ 485.678150][ T21] *** DEADLOCK *** [ 485.678150][ T21] [ 485.686279][ T21] 2 locks held by kworker/1:0/21: [ 485.691343][ T21] #0: ffff888012469d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x86d/0x1710 [ 485.701705][ T21] #1: ffffc900003cfda8 ((work_completion)(&(&conn->timeout_work)->work)){+.+.}-{0:0}, at: process_one_work+0x8a1/0x1710 [ 485.714406][ T21] [ 485.714406][ T21] stack backtrace: [ 485.720281][ T21] CPU: 1 PID: 21 Comm: kworker/1:0 Not tainted 6.2.0-rc2-syzkaller-00117-g88603b6dc419 #0 [ 485.730164][ T21] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022 [ 485.740314][ T21] Workqueue: events sco_sock_timeout [ 485.745597][ T21] Call Trace: [ 485.748872][ T21] [ 485.751796][ T21] dump_stack_lvl+0xd1/0x138 [ 485.756390][ T21] check_noncircular+0x25f/0x2e0 [ 485.761331][ T21] ? print_circular_bug+0x1e0/0x1e0 [ 485.766540][ T21] ? filter_irq_stacks+0x90/0x90 [ 485.771544][ T21] ? save_trace+0x43/0xad0 [ 485.775976][ T21] __lock_acquire+0x2a43/0x56d0 [ 485.781015][ T21] ? lockdep_hardirqs_on_prepare+0x410/0x410 [ 485.787024][ T21] ? lockdep_hardirqs_on_prepare+0x410/0x410 [ 485.793282][ T21] lock_acquire+0x1e3/0x630 [ 485.797812][ T21] ? sco_sock_timeout+0xd1/0x290 [ 485.802746][ T21] ? lock_release+0x810/0x810 [ 485.807427][ T21] ? sco_sock_timeout+0xbd/0x290 [ 485.812368][ T21] ? lock_downgrade+0x6e0/0x6e0 [ 485.817227][ T21] ? do_raw_spin_lock+0x124/0x2b0 [ 485.822267][ T21] ? rwlock_bug.part.0+0x90/0x90 [ 485.827202][ T21] lock_sock_nested+0x3a/0xf0 [ 485.831880][ T21] ? sco_sock_timeout+0xd1/0x290 [ 485.836822][ T21] sco_sock_timeout+0xd1/0x290 [ 485.841580][ T21] process_one_work+0x9bf/0x1710 [ 485.846517][ T21] ? pwq_dec_nr_in_flight+0x2a0/0x2a0 [ 485.851886][ T21] ? rwlock_bug.part.0+0x90/0x90 [ 485.856817][ T21] ? _raw_spin_lock_irq+0x45/0x50 [ 485.861846][ T21] worker_thread+0x669/0x1090 [ 485.866523][ T21] ? process_one_work+0x1710/0x1710 [ 485.871716][ T21] kthread+0x2e8/0x3a0 [ 485.875781][ T21] ? kthread_complete_and_exit+0x40/0x40 [ 485.881409][ T21] ret_from_fork+0x1f/0x30 [ 485.885839][ T21]