INFO: task kworker/1:1:45 blocked for more than 140 seconds. Not tainted 4.19.211-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. kauditd_printk_skb: 54 callbacks suppressed audit: type=1804 audit(1674736350.475:2510): pid=9923 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.1" name="/root/syzkaller-testdir3795393316/syzkaller.3cuT5c/864/bus" dev="sda1" ino=14627 res=1 kworker/1:1 D26376 45 2 0x80000000 Workqueue: usb_hub_wq hub_event Call Trace: context_switch kernel/sched/core.c:2828 [inline] __schedule+0x887/0x2040 kernel/sched/core.c:3517 audit: type=1804 audit(1674736350.485:2511): pid=9920 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=ToMToU comm="syz-executor.1" name="/root/syzkaller-testdir3795393316/syzkaller.3cuT5c/864/bus" dev="sda1" ino=14627 res=1 audit: type=1804 audit(1674736350.725:2512): pid=9904 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.3" name="/root/syzkaller-testdir1898564892/syzkaller.SB0mDv/808/bus" dev="sda1" ino=14674 res=1 schedule+0x8d/0x1b0 kernel/sched/core.c:3561 usb_kill_urb.part.0+0x197/0x220 drivers/usb/core/urb.c:697 usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:692 audit: type=1804 audit(1674736350.735:2513): pid=9904 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=ToMToU comm="syz-executor.3" name="/root/syzkaller-testdir1898564892/syzkaller.SB0mDv/808/bus" dev="sda1" ino=14674 res=1 usb_start_wait_urb+0x252/0x4c0 drivers/usb/core/message.c:63 audit: type=1804 audit(1674736350.795:2514): pid=9953 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=ToMToU comm="syz-executor.3" name="/root/syzkaller-testdir1898564892/syzkaller.SB0mDv/808/bus" dev="sda1" ino=14674 res=1 usb_internal_control_msg drivers/usb/core/message.c:101 [inline] usb_control_msg+0x31c/0x4a0 drivers/usb/core/message.c:152 audit: type=1804 audit(1674736350.805:2515): pid=9954 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.3" name="/root/syzkaller-testdir1898564892/syzkaller.SB0mDv/808/bus" dev="sda1" ino=14674 res=1 usb_get_descriptor+0xc5/0x1b0 drivers/usb/core/message.c:654 usb_get_device_descriptor+0x81/0xf0 drivers/usb/core/message.c:926 audit: type=1804 audit(1674736350.805:2516): pid=9955 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=ToMToU comm="syz-executor.3" name="/root/syzkaller-testdir1898564892/syzkaller.SB0mDv/808/bus" dev="sda1" ino=14674 res=1 hub_port_init+0x74b/0x3120 drivers/usb/core/hub.c:4799 hub_port_connect drivers/usb/core/hub.c:5070 [inline] hub_port_connect_change drivers/usb/core/hub.c:5253 [inline] port_event drivers/usb/core/hub.c:5361 [inline] hub_event+0x1ccd/0x44a0 drivers/usb/core/hub.c:5441 process_one_work+0x864/0x1570 kernel/workqueue.c:2153 worker_thread+0x64c/0x1130 kernel/workqueue.c:2296 kthread+0x33f/0x460 kernel/kthread.c:259 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415 Showing all locks held in the system: 3 locks held by kworker/u4:2/33: 5 locks held by kworker/1:1/45: #0: 000000001be1c709 ((wq_completion)"usb_hub_wq"){+.+.}, at: process_one_work+0x767/0x1570 kernel/workqueue.c:2124 #1: 00000000e4001551 ((work_completion)(&hub->events)){+.+.}, at: process_one_work+0x79c/0x1570 kernel/workqueue.c:2128 #2: 00000000d3fb2c62 (&dev->mutex){....}, at: device_lock include/linux/device.h:1174 [inline] #2: 00000000d3fb2c62 (&dev->mutex){....}, at: hub_event+0x11e/0x44a0 drivers/usb/core/hub.c:5387 audit: type=1804 audit(1674736351.836:2517): pid=9981 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.1" name="/root/syzkaller-testdir3795393316/syzkaller.3cuT5c/865/bus" dev="sda1" ino=14020 res=1 audit: type=1804 audit(1674736351.866:2518): pid=9978 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=ToMToU comm="syz-executor.1" name="/root/syzkaller-testdir3795393316/syzkaller.3cuT5c/865/bus" dev="sda1" ino=14020 res=1 #3: 000000009645e0a7 (&port_dev->status_lock){+.+.}, at: usb_lock_port drivers/usb/core/hub.c:2983 [inline] #3: 000000009645e0a7 (&port_dev->status_lock){+.+.}, at: hub_port_connect drivers/usb/core/hub.c:5069 [inline] #3: 000000009645e0a7 (&port_dev->status_lock){+.+.}, at: hub_port_connect_change drivers/usb/core/hub.c:5253 [inline] #3: 000000009645e0a7 (&port_dev->status_lock){+.+.}, at: port_event drivers/usb/core/hub.c:5361 [inline] #3: 000000009645e0a7 (&port_dev->status_lock){+.+.}, at: hub_event+0x1cb8/0x44a0 drivers/usb/core/hub.c:5441 #4: 0000000071b929b5 (hcd->address0_mutex){+.+.}, at: hub_port_init+0x1b9/0x3120 drivers/usb/core/hub.c:4578 1 lock held by khungtaskd/1570: #0: 00000000bcaa1005 (rcu_read_lock){....}, at: debug_show_all_locks+0x53/0x265 kernel/locking/lockdep.c:4441 1 lock held by in:imklog/7800: #0: 00000000dafc4fe3 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x26f/0x310 fs/file.c:767 1 lock held by syz-executor.2/8132: #0: 0000000077300ce2 (rcu_preempt_state.exp_mutex){+.+.}, at: exp_funnel_lock kernel/rcu/tree_exp.h:297 [inline] #0: 0000000077300ce2 (rcu_preempt_state.exp_mutex){+.+.}, at: _synchronize_rcu_expedited+0x4dc/0x6f0 kernel/rcu/tree_exp.h:667 3 locks held by kworker/u4:7/9521: 2 locks held by kworker/1:3/9628: #0: 0000000077bb8cbd ((wq_completion)"rcu_gp"){+.+.}, at: process_one_work+0x767/0x1570 kernel/workqueue.c:2124 #1: 000000004e108e6f ((work_completion)(&rew.rew_work)){+.+.}, at: process_one_work+0x79c/0x1570 kernel/workqueue.c:2128 3 locks held by syz-executor.1/9979: 1 lock held by syz-executor.5/9986: 3 locks held by syz-executor.4/10021: 5 locks held by syz-executor.0/10022: ============================================= NMI backtrace for cpu 1 CPU: 1 PID: 1570 Comm: khungtaskd Not tainted 4.19.211-syzkaller #0 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/12/2023 Call Trace: __dump_stack lib/dump_stack.c:77 [inline] dump_stack+0x1fc/0x2ef lib/dump_stack.c:118 nmi_cpu_backtrace.cold+0x63/0xa2 lib/nmi_backtrace.c:101 nmi_trigger_cpumask_backtrace+0x1a6/0x1f0 lib/nmi_backtrace.c:62 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline] check_hung_uninterruptible_tasks kernel/hung_task.c:203 [inline] watchdog+0x991/0xe60 kernel/hung_task.c:287 kthread+0x33f/0x460 kernel/kthread.c:259 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415 Sending NMI from CPU 1 to CPUs 0: NMI backtrace for cpu 0 CPU: 0 PID: 9 Comm: ksoftirqd/0 Not tainted 4.19.211-syzkaller #0 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/12/2023 RIP: 0010:__read_once_size include/linux/compiler.h:263 [inline] RIP: 0010:bpf_prog_array_valid include/linux/trace_events.h:307 [inline] RIP: 0010:perf_trace_lock+0x124/0x4b0 include/trace/events/lock.h:39 Code: c1 e9 03 80 3c 11 00 0f 85 75 02 00 00 49 8d bc 24 80 00 00 00 48 03 1c c5 00 af cf 89 48 b8 00 00 00 00 00 fc ff df 48 89 fa <48> c1 ea 03 80 3c 02 00 0f 85 40 02 00 00 49 8b 84 24 80 00 00 00 RSP: 0018:ffff8880b5a5fa50 EFLAGS: 00000082 RAX: dffffc0000000000 RBX: ffffe8ffffc7b868 RCX: 1ffffffff139f5e0 RDX: ffffffff89f6d3e0 RSI: ffffffff83771e31 RDI: ffffffff89f6d3e0 RBP: ffff8880b5a5fb28 R08: 0000000000000286 R09: 0000000000000000 R10: 0000000000000005 R11: 0000000000000000 R12: ffffffff89f6d360 R13: ffffffff8d3ffd60 R14: ffffffff814a7850 R15: ffff8880b5a5fb00 FS: 0000000000000000(0000) GS:ffff8880ba000000(0000) knlGS:0000000000000000 CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 CR2: 00007fb08e095f58 CR3: 00000000aee07000 CR4: 00000000003406f0 DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 Call Trace: trace_lock_release include/trace/events/lock.h:58 [inline] lock_release+0x4e8/0x8b0 kernel/locking/lockdep.c:3926 __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:158 [inline] _raw_spin_unlock_irqrestore+0x1b/0xe0 kernel/locking/spinlock.c:184 debug_object_deactivate lib/debugobjects.c:568 [inline] debug_object_deactivate+0x1f9/0x2e0 lib/debugobjects.c:529 debug_rcu_head_unqueue kernel/rcu/rcu.h:205 [inline] rcu_do_batch kernel/rcu/tree.c:2583 [inline] invoke_rcu_callbacks kernel/rcu/tree.c:2897 [inline] __rcu_process_callbacks kernel/rcu/tree.c:2864 [inline] rcu_process_callbacks+0x9be/0x18b0 kernel/rcu/tree.c:2881 __do_softirq+0x265/0x980 kernel/softirq.c:292 run_ksoftirqd+0x57/0x110 kernel/softirq.c:653 smpboot_thread_fn+0x655/0x9e0 kernel/smpboot.c:164 kthread+0x33f/0x460 kernel/kthread.c:259 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415