Warning: Permanently added '10.128.1.97' (ED25519) to the list of known hosts. 2023/11/20 14:42:31 ignoring optional flag "sandboxArg"="0" 2023/11/20 14:42:31 parsed 1 programs 2023/11/20 14:42:31 executed programs: 0 [ 45.192622][ T2665] Adding 124996k swap on ./swap-file. Priority:0 extents:1 across:124996k [ 45.261061][ T2699] Bluetooth: hci0: unexpected cc 0x0c03 length: 249 > 1 [ 45.266710][ T2700] Bluetooth: hci1: unexpected cc 0x0c03 length: 249 > 1 [ 45.268360][ T2699] Bluetooth: hci2: unexpected cc 0x0c03 length: 249 > 1 [ 45.276627][ T2700] Bluetooth: hci5: unexpected cc 0x0c03 length: 249 > 1 [ 45.289070][ T2701] Bluetooth: hci0: unexpected cc 0x1003 length: 249 > 9 [ 45.289287][ T2699] Bluetooth: hci3: unexpected cc 0x0c03 length: 249 > 1 [ 45.296326][ T2700] Bluetooth: hci1: unexpected cc 0x1003 length: 249 > 9 [ 45.303377][ T2699] Bluetooth: hci4: unexpected cc 0x0c03 length: 249 > 1 [ 45.310697][ T2700] Bluetooth: hci2: unexpected cc 0x1003 length: 249 > 9 [ 45.318081][ T2699] Bluetooth: hci3: unexpected cc 0x1003 length: 249 > 9 [ 45.324351][ T2700] Bluetooth: hci1: unexpected cc 0x1001 length: 249 > 9 [ 45.330943][ T2702] Bluetooth: hci5: unexpected cc 0x1003 length: 249 > 9 [ 45.337977][ T2700] Bluetooth: hci2: unexpected cc 0x1001 length: 249 > 9 [ 45.345317][ T2699] Bluetooth: hci0: unexpected cc 0x1001 length: 249 > 9 [ 45.352512][ T2700] Bluetooth: hci2: unexpected cc 0x0c23 length: 249 > 4 [ 45.359090][ T2699] Bluetooth: hci0: unexpected cc 0x0c23 length: 249 > 4 [ 45.365820][ T2700] Bluetooth: hci4: unexpected cc 0x1003 length: 249 > 9 [ 45.372789][ T2699] Bluetooth: hci3: unexpected cc 0x1001 length: 249 > 9 [ 45.386566][ T2702] Bluetooth: hci5: unexpected cc 0x1001 length: 249 > 9 [ 45.386600][ T2700] Bluetooth: hci4: unexpected cc 0x1001 length: 249 > 9 [ 45.393595][ T2699] Bluetooth: hci2: unexpected cc 0x0c25 length: 249 > 3 [ 45.402030][ T2700] Bluetooth: hci5: unexpected cc 0x0c23 length: 249 > 4 [ 45.408191][ T2699] Bluetooth: hci1: unexpected cc 0x0c23 length: 249 > 4 [ 45.414812][ T2703] Bluetooth: hci0: unexpected cc 0x0c25 length: 249 > 3 [ 45.422159][ T2700] Bluetooth: hci2: unexpected cc 0x0c38 length: 249 > 2 [ 45.428880][ T2701] Bluetooth: hci4: unexpected cc 0x0c23 length: 249 > 4 [ 45.435443][ T2699] Bluetooth: hci3: unexpected cc 0x0c23 length: 249 > 4 [ 45.442808][ T2701] Bluetooth: hci4: unexpected cc 0x0c25 length: 249 > 3 [ 45.449356][ T2700] Bluetooth: hci5: unexpected cc 0x0c25 length: 249 > 3 [ 45.456531][ T2701] Bluetooth: hci4: unexpected cc 0x0c38 length: 249 > 2 [ 45.463360][ T2699] Bluetooth: hci0: unexpected cc 0x0c38 length: 249 > 2 [ 45.470184][ T2703] Bluetooth: hci1: unexpected cc 0x0c25 length: 249 > 3 [ 45.483725][ T2701] Bluetooth: hci5: unexpected cc 0x0c38 length: 249 > 2 [ 45.486630][ T2703] Bluetooth: hci1: unexpected cc 0x0c38 length: 249 > 2 [ 45.491163][ T2699] Bluetooth: hci3: unexpected cc 0x0c25 length: 249 > 3 [ 45.504900][ T2699] Bluetooth: hci3: unexpected cc 0x0c38 length: 249 > 2 [ 45.715304][ T2683] chnl_net:caif_netlink_parms(): no params data found [ 45.758452][ T2681] chnl_net:caif_netlink_parms(): no params data found [ 45.765845][ T2682] chnl_net:caif_netlink_parms(): no params data found [ 45.785324][ T2688] chnl_net:caif_netlink_parms(): no params data found [ 45.793973][ T2676] chnl_net:caif_netlink_parms(): no params data found [ 45.828111][ T2692] chnl_net:caif_netlink_parms(): no params data found [ 47.561061][ T2689] Bluetooth: hci2: command 0x0409 tx timeout [ 47.561059][ T2698] Bluetooth: hci1: command 0x0409 tx timeout [ 47.567234][ T2689] Bluetooth: hci3: command 0x0409 tx timeout [ 47.567273][ T2689] Bluetooth: hci5: command 0x0409 tx timeout [ 47.573305][ T2698] Bluetooth: hci4: command 0x0409 tx timeout [ 47.579341][ T2689] Bluetooth: hci0: command 0x0409 tx timeout [ 48.442751][ T2683] 8021q: adding VLAN 0 to HW filter on device bond0 [ 48.555213][ T2681] 8021q: adding VLAN 0 to HW filter on device bond0 [ 48.594040][ T2688] 8021q: adding VLAN 0 to HW filter on device bond0 [ 48.618284][ T2676] 8021q: adding VLAN 0 to HW filter on device bond0 [ 48.672471][ T2682] 8021q: adding VLAN 0 to HW filter on device bond0 [ 48.766881][ T2692] 8021q: adding VLAN 0 to HW filter on device bond0 [ 49.637021][ T2689] Bluetooth: hci2: command 0x041b tx timeout [ 49.637033][ T2699] Bluetooth: hci0: command 0x041b tx timeout [ 49.643022][ T2689] Bluetooth: hci4: command 0x041b tx timeout [ 49.649059][ T2701] Bluetooth: hci5: command 0x041b tx timeout [ 49.655025][ T2689] Bluetooth: hci1: command 0x041b tx timeout [ 49.661260][ T2698] Bluetooth: hci3: command 0x041b tx timeout [ 50.448245][ T2683] 8021q: adding VLAN 0 to HW filter on device batadv0 [ 50.557915][ T2688] 8021q: adding VLAN 0 to HW filter on device batadv0 [ 50.628194][ T2682] 8021q: adding VLAN 0 to HW filter on device batadv0 [ 50.715894][ T2676] 8021q: adding VLAN 0 to HW filter on device batadv0 [ 50.752266][ T2681] 8021q: adding VLAN 0 to HW filter on device batadv0 [ 50.997382][ T2692] 8021q: adding VLAN 0 to HW filter on device batadv0 [ 51.719328][ T2701] Bluetooth: hci0: command 0x040f tx timeout [ 51.725349][ T2701] Bluetooth: hci1: command 0x040f tx timeout [ 51.726523][ T2699] Bluetooth: hci2: command 0x040f tx timeout [ 51.732530][ T2701] Bluetooth: hci5: command 0x040f tx timeout [ 51.737433][ T2689] Bluetooth: hci3: command 0x040f tx timeout [ 51.749385][ T2698] Bluetooth: hci4: command 0x040f tx timeout [ 53.797234][ T2698] Bluetooth: hci5: command 0x0419 tx timeout [ 53.803273][ T2698] Bluetooth: hci1: command 0x0419 tx timeout [ 53.812294][ T2699] Bluetooth: hci0: command 0x0419 tx timeout [ 53.818372][ T2689] Bluetooth: hci4: command 0x0419 tx timeout [ 53.824356][ T2689] Bluetooth: hci2: command 0x0419 tx timeout [ 53.830442][ T2048] Bluetooth: hci3: command 0x0419 tx timeout [ 54.352977][ T0] NOHZ tick-stop error: local softirq work is pending, handler #300!!! [ 54.364359][ T0] NOHZ tick-stop error: local softirq work is pending, handler #208!!! [ 54.405149][ T0] NOHZ tick-stop error: local softirq work is pending, handler #208!!! [ 54.417936][ T0] NOHZ tick-stop error: local softirq work is pending, handler #208!!! [ 54.427767][ T0] NOHZ tick-stop error: local softirq work is pending, handler #08!!! [ 54.479410][ T0] NOHZ tick-stop error: local softirq work is pending, handler #08!!! [ 54.492566][ T0] NOHZ tick-stop error: local softirq work is pending, handler #208!!! [ 54.501635][ T0] NOHZ tick-stop error: local softirq work is pending, handler #208!!! [ 54.501837][ T0] NOHZ tick-stop error: local softirq work is pending, handler #208!!! [ 54.520638][ T0] NOHZ tick-stop error: local softirq work is pending, handler #108!!! [ 54.520732][ T0] NOHZ tick-stop error: local softirq work is pending, handler #208!!! [ 54.568335][ T4802] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.4'. [ 54.611498][ T4802] vxcan0: entered promiscuous mode [ 54.674820][ C0] [ 54.677162][ C0] ====================================================== [ 54.684161][ C0] WARNING: possible circular locking dependency detected [ 54.691531][ C0] 6.7.0-rc2-syzkaller #0 Not tainted [ 54.696795][ C0] ------------------------------------------------------ [ 54.703790][ C0] ksoftirqd/0/16 is trying to acquire lock: [ 54.709735][ C0] ffff888113477088 (&priv->active_session_list_lock){+.-.}-{2:2}, at: j1939_session_activate+0x23/0x110 [ 54.720823][ C0] [ 54.720823][ C0] but task is already holding lock: [ 54.728161][ C0] ffff888140a945c8 (&jsk->sk_session_queue_lock){+.-.}-{2:2}, at: j1939_sk_queue_activate_next+0x2d/0x150 [ 54.739438][ C0] [ 54.739438][ C0] which lock already depends on the new lock. [ 54.739438][ C0] [ 54.749814][ C0] [ 54.749814][ C0] the existing dependency chain (in reverse order) is: [ 54.758804][ C0] [ 54.758804][ C0] -> #2 (&jsk->sk_session_queue_lock){+.-.}-{2:2}: [ 54.767477][ C0] _raw_spin_lock_bh+0x35/0x50 [ 54.772739][ C0] j1939_sk_queue_drop_all+0x22/0xc0 [ 54.778518][ C0] j1939_sk_netdev_event_netdown+0x3f/0x80 [ 54.784819][ C0] j1939_netdev_notify+0xb1/0xf0 [ 54.790251][ C0] notifier_call_chain+0x69/0xf0 [ 54.795702][ C0] __dev_notify_flags+0xe8/0x180 [ 54.801133][ C0] dev_change_flags+0x4c/0x60 [ 54.806350][ C0] do_setlink+0x4f3/0x1170 [ 54.811267][ C0] rtnl_newlink+0xb8c/0xe40 [ 54.816266][ C0] rtnetlink_rcv_msg+0x398/0x670 [ 54.821704][ C0] netlink_rcv_skb+0xd9/0x100 [ 54.826876][ C0] netlink_unicast+0x23b/0x320 [ 54.832134][ C0] netlink_sendmsg+0x3ad/0x440 [ 54.837394][ C0] ____sys_sendmsg+0x19a/0x240 [ 54.842655][ C0] ___sys_sendmsg+0x28f/0x2d0 [ 54.847828][ C0] __se_sys_sendmsg+0xf7/0x130 [ 54.853087][ C0] do_syscall_64+0x45/0x110 [ 54.858086][ C0] entry_SYSCALL_64_after_hwframe+0x63/0x6b [ 54.864561][ C0] [ 54.864561][ C0] -> #1 (&priv->j1939_socks_lock){+.-.}-{2:2}: [ 54.872864][ C0] _raw_spin_lock_bh+0x35/0x50 [ 54.878124][ C0] j1939_sk_errqueue+0x48/0xb0 [ 54.883385][ C0] j1939_session_put+0x55/0x160 [ 54.888915][ C0] j1939_cancel_active_session+0x62/0x150 [ 54.895126][ C0] j1939_netdev_notify+0xa9/0xf0 [ 54.900558][ C0] notifier_call_chain+0x69/0xf0 [ 54.906075][ C0] __dev_notify_flags+0xe8/0x180 [ 54.911508][ C0] dev_change_flags+0x4c/0x60 [ 54.916684][ C0] do_setlink+0x4f3/0x1170 [ 54.921599][ C0] rtnl_newlink+0xb8c/0xe40 [ 54.926601][ C0] rtnetlink_rcv_msg+0x398/0x670 [ 54.932040][ C0] netlink_rcv_skb+0xd9/0x100 [ 54.937215][ C0] netlink_unicast+0x23b/0x320 [ 54.942476][ C0] netlink_sendmsg+0x3ad/0x440 [ 54.947739][ C0] ____sys_sendmsg+0x19a/0x240 [ 54.952999][ C0] ___sys_sendmsg+0x28f/0x2d0 [ 54.958205][ C0] __se_sys_sendmsg+0xf7/0x130 [ 54.963468][ C0] do_syscall_64+0x45/0x110 [ 54.968467][ C0] entry_SYSCALL_64_after_hwframe+0x63/0x6b [ 54.975549][ C0] [ 54.975549][ C0] -> #0 (&priv->active_session_list_lock){+.-.}-{2:2}: [ 54.984550][ C0] __lock_acquire+0x11f2/0x2480 [ 54.989905][ C0] lock_acquire+0xea/0x260 [ 54.994816][ C0] _raw_spin_lock_bh+0x35/0x50 [ 55.000075][ C0] j1939_session_activate+0x23/0x110 [ 55.005949][ C0] j1939_sk_queue_activate_next+0xd6/0x150 [ 55.012251][ C0] j1939_xtp_rx_eoma+0x14b/0x1c0 [ 55.017686][ C0] j1939_tp_recv+0x2ea/0x4a0 [ 55.022786][ C0] j1939_can_recv+0x1e4/0x290 [ 55.027957][ C0] can_rcv_filter+0x76/0x160 [ 55.033044][ C0] can_receive+0x107/0x190 [ 55.037956][ C0] can_rcv+0x4b/0x90 [ 55.042348][ C0] __netif_receive_skb+0x50/0xe0 [ 55.047779][ C0] process_backlog+0x1b6/0x2d0 [ 55.053037][ C0] __napi_poll+0x24/0x1c0 [ 55.057861][ C0] net_rx_action+0x1b9/0x390 [ 55.062948][ C0] __do_softirq+0x146/0x3c8 [ 55.067945][ C0] run_ksoftirqd+0x50/0x80 [ 55.072861][ C0] smpboot_thread_fn+0x152/0x200 [ 55.078297][ C0] kthread+0xe5/0x100 [ 55.082863][ C0] ret_from_fork+0x2e/0x40 [ 55.087782][ C0] ret_from_fork_asm+0x11/0x20 [ 55.093046][ C0] [ 55.093046][ C0] other info that might help us debug this: [ 55.093046][ C0] [ 55.103250][ C0] Chain exists of: [ 55.103250][ C0] &priv->active_session_list_lock --> &priv->j1939_socks_lock --> &jsk->sk_session_queue_lock [ 55.103250][ C0] [ 55.119455][ C0] Possible unsafe locking scenario: [ 55.119455][ C0] [ 55.126888][ C0] CPU0 CPU1 [ 55.132237][ C0] ---- ---- [ 55.137581][ C0] lock(&jsk->sk_session_queue_lock); [ 55.143015][ C0] lock(&priv->j1939_socks_lock); [ 55.150619][ C0] lock(&jsk->sk_session_queue_lock); [ 55.158570][ C0] lock(&priv->active_session_list_lock); [ 55.164354][ C0] [ 55.164354][ C0] *** DEADLOCK *** [ 55.164354][ C0] [ 55.172482][ C0] 3 locks held by ksoftirqd/0/16: [ 55.177478][ C0] #0: ffffffff83f7d500 (rcu_read_lock){....}-{1:2}, at: process_backlog+0x14a/0x2d0 [ 55.186913][ C0] #1: ffffffff83f7d500 (rcu_read_lock){....}-{1:2}, at: can_receive+0x5f/0x190 [ 55.195911][ C0] #2: ffff888140a945c8 (&jsk->sk_session_queue_lock){+.-.}-{2:2}, at: j1939_sk_queue_activate_next+0x2d/0x150 [ 55.207619][ C0] [ 55.207619][ C0] stack backtrace: [ 55.213514][ C0] CPU: 0 PID: 16 Comm: ksoftirqd/0 Not tainted 6.7.0-rc2-syzkaller #0 [ 55.221646][ C0] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 11/10/2023 [ 55.231693][ C0] Call Trace: [ 55.234960][ C0] [ 55.237876][ C0] dump_stack_lvl+0x8d/0xe0 [ 55.242460][ C0] check_noncircular+0x115/0x140 [ 55.247399][ C0] __lock_acquire+0x11f2/0x2480 [ 55.252228][ C0] ? debug_check_no_obj_freed+0xc7/0x270 [ 55.257856][ C0] ? debug_object_deactivate+0x4a/0x140 [ 55.263398][ C0] ? j1939_session_activate+0x23/0x110 [ 55.268843][ C0] lock_acquire+0xea/0x260 [ 55.273247][ C0] ? j1939_session_activate+0x23/0x110 [ 55.278684][ C0] ? j1939_session_activate+0x23/0x110 [ 55.284121][ C0] _raw_spin_lock_bh+0x35/0x50 [ 55.288859][ C0] ? j1939_session_activate+0x23/0x110 [ 55.294291][ C0] j1939_session_activate+0x23/0x110 [ 55.299550][ C0] j1939_sk_queue_activate_next+0xd6/0x150 [ 55.305329][ C0] j1939_xtp_rx_eoma+0x14b/0x1c0 [ 55.310253][ C0] j1939_tp_recv+0x2ea/0x4a0 [ 55.314836][ C0] j1939_can_recv+0x1e4/0x290 [ 55.319488][ C0] can_rcv_filter+0x76/0x160 [ 55.324063][ C0] ? can_receive+0x5f/0x190 [ 55.328630][ C0] can_receive+0x107/0x190 [ 55.333020][ C0] ? process_backlog+0x14a/0x2d0 [ 55.337935][ C0] can_rcv+0x4b/0x90 [ 55.341818][ C0] __netif_receive_skb+0x50/0xe0 [ 55.346746][ C0] process_backlog+0x1b6/0x2d0 [ 55.351513][ C0] __napi_poll+0x24/0x1c0 [ 55.355821][ C0] net_rx_action+0x1b9/0x390 [ 55.360393][ C0] __do_softirq+0x146/0x3c8 [ 55.364958][ C0] ? run_ksoftirqd+0x50/0x80 [ 55.369525][ C0] run_ksoftirqd+0x50/0x80 [ 55.373917][ C0] smpboot_thread_fn+0x152/0x200 [ 55.378829][ C0] ? smpboot_unregister_percpu_thread+0xe0/0xe0 [ 55.385058][ C0] kthread+0xe5/0x100 [ 55.389016][ C0] ? kthread_blkcg+0x30/0x30 [ 55.393583][ C0] ret_from_fork+0x2e/0x40 [ 55.397976][ C0] ? kthread_blkcg+0x30/0x30 [ 55.402540][ C0] ret_from_fork_asm+0x11/0x20 [ 55.407290][ C0] [ 55.416610][ C0] vxcan0: j1939_xtp_rx_dat: no tx connection found [ 55.423144][ C0] vxcan0: j1939_xtp_rx_dat: no tx connection found [ 55.433836][ T4804] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.0'. 2023/11/20 14:42:41 executed programs: 6 [ 55.497786][ T4804] vxcan0: entered promiscuous mode [ 55.509410][ T4810] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.2'. [ 55.518956][ T4810] vxcan0: entered promiscuous mode [ 55.545578][ T4819] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.2'. [ 55.564172][ T4815] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.4'. [ 55.583114][ T4827] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.4'. [ 55.626340][ T4825] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.0'. [ 55.636936][ T4828] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.2'. [ 55.674585][ T4839] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.3'. [ 55.706106][ T4839] vxcan0: entered promiscuous mode [ 55.713561][ T4843] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.2'. [ 55.816627][ T4863] vxcan0: entered promiscuous mode [ 55.896710][ T4874] vxcan0: entered promiscuous mode [ 55.902075][ C0] vxcan0: j1939_xtp_rx_dat: no tx connection found [ 55.908759][ C0] vxcan0: j1939_xtp_rx_dat: no rx connection found [ 56.179757][ C0] vxcan0: j1939_tp_rxtimer: 0xffff8881138cc600: rx timeout, send abort [ 56.245419][ C1] vxcan0: j1939_tp_rxtimer: 0xffff88811360c800: rx timeout, send abort [ 56.688029][ C0] vxcan0: j1939_tp_rxtimer: 0xffff8881138cc600: abort rx timeout. Force session deactivation [ 56.753729][ C1] vxcan0: j1939_tp_rxtimer: 0xffff88811360c800: abort rx timeout. Force session deactivation [ 59.581777][ T6651] __nla_validate_parse: 892 callbacks suppressed [ 59.581780][ T6651] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.2'. [ 59.598159][ T6657] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.3'. [ 59.608427][ T6655] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.5'. [ 59.626207][ T6662] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.0'. [ 59.635814][ T6663] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.1'. [ 59.653250][ T6660] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.3'. [ 59.671516][ T6668] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.5'. [ 59.681974][ T6666] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.2'. [ 59.693401][ T6670] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.0'. [ 59.707436][ T6665] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.4'. 2023/11/20 14:42:46 executed programs: 1137 [ 64.591028][ T9464] __nla_validate_parse: 1396 callbacks suppressed [ 64.591032][ T9464] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.4'. [ 64.608676][ T9474] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.1'. [ 64.618663][ T9467] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.2'. [ 64.631064][ T9471] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.3'. [ 64.646449][ T9468] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.5'. [ 64.658453][ T9472] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.0'. [ 64.669675][ T9476] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.4'. [ 64.680437][ T9480] netlink: 36 bytes leftover after parsing attributes in process `syz-executor.2'.