bisecting fixing commit since f6d5cb9e2c06f7d583dd9f4f7cca21d13d78c32a building syzkaller on 816e0689d7d9d8321f8bf360740f0e516aee15ca testing commit f6d5cb9e2c06f7d583dd9f4f7cca21d13d78c32a compiler: gcc version 8.4.1 20210217 (GCC) kernel signature: c4abebe2d67140c7d1763ca1cee6651d4646dc69b31d50ed79da4da8aaf07b35 run #0: crashed: KASAN: use-after-free Read in __queue_work run #1: crashed: WARNING: ODEBUG bug in bt_host_release run #2: crashed: general protection fault in __queue_work run #3: crashed: WARNING: ODEBUG bug in bt_host_release run #4: crashed: WARNING: ODEBUG bug in bt_host_release run #5: crashed: general protection fault in __queue_work run #6: crashed: WARNING: ODEBUG bug in bt_host_release run #7: crashed: INFO: task hung in hci_req_sync run #8: OK run #9: OK run #10: OK run #11: OK run #12: OK run #13: OK run #14: OK run #15: OK run #16: OK run #17: OK run #18: OK run #19: OK reproducer seems to be flaky testing current HEAD b172b44fcb1771e083aad806fa96f3f60e2ddfac testing commit b172b44fcb1771e083aad806fa96f3f60e2ddfac compiler: gcc version 8.4.1 20210217 (GCC) kernel signature: 6dbdc45edfcaae629821058bdaefc4526c60178a61817e3f65e6c507888760f0 run #0: basic kernel testing failed: failed to copy test binary to VM: failed to run ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor925681362" "root@10.128.15.213:./syz-executor925681362"]: exit status 1 Connection timed out during banner exchange Connection to 10.128.15.213 port 22 timed out lost connection run #1: crashed: INFO: task hung in hci_req_sync run #2: OK run #3: OK run #4: OK run #5: OK run #6: OK run #7: OK run #8: OK run #9: OK run #10: OK run #11: OK run #12: OK run #13: OK run #14: OK run #15: OK run #16: OK run #17: OK run #18: OK run #19: OK Reproducer flagged being flaky revisions tested: 2, total time: 41m52.31229072s (build: 17m31.996219296s, test: 23m45.431318581s) the crash still happens on HEAD commit msg: Linux 4.19.206 crash: INFO: task hung in hci_req_sync Bluetooth: hci6: command 0x0409 tx timeout Bluetooth: hci1: command 0x0401 tx timeout Bluetooth: hci6: command 0x041b tx timeout Bluetooth: hci1: command 0x0401 tx timeout Bluetooth: hci6: command 0x040f tx timeout INFO: task syz-executor.0:16050 blocked for more than 140 seconds. Not tainted 4.19.206-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.0 D28232 16050 5931 0x00000004 Call Trace: context_switch kernel/sched/core.c:2828 [inline] __schedule+0x80c/0x1f70 kernel/sched/core.c:3517 schedule+0x7f/0x1b0 kernel/sched/core.c:3561 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3619 __mutex_lock_common kernel/locking/mutex.c:1015 [inline] __mutex_lock+0x4ba/0x1190 kernel/locking/mutex.c:1083 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1098 hci_req_sync+0x32/0xa0 net/bluetooth/hci_request.c:275 hci_inquiry+0x593/0x750 net/bluetooth/hci_core.c:1310 hci_sock_ioctl+0x19e/0x680 net/bluetooth/hci_sock.c:1053 Bluetooth: hci1: command 0x0401 tx timeout sock_do_ioctl+0xd9/0x240 net/socket.c:1015 sock_ioctl+0x281/0x500 net/socket.c:1135 vfs_ioctl fs/ioctl.c:46 [inline] file_ioctl fs/ioctl.c:501 [inline] do_vfs_ioctl+0x196/0x10c0 fs/ioctl.c:688 ksys_ioctl+0x62/0x90 fs/ioctl.c:705 __do_sys_ioctl fs/ioctl.c:712 [inline] __se_sys_ioctl fs/ioctl.c:710 [inline] __x64_sys_ioctl+0x6e/0xb0 fs/ioctl.c:710 do_syscall_64+0xd0/0x4e0 arch/x86/entry/common.c:293 entry_SYSCALL_64_after_hwframe+0x49/0xbe RIP: 0033:0x465109 Code: Bad RIP value. RSP: 002b:00007fb75c9b5188 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 RAX: ffffffffffffffda RBX: 000000000055cf00 RCX: 0000000000465109 RDX: 0000000020000200 RSI: 00000000800448f0 RDI: 0000000000000004 RBP: 00000000004af711 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 000000000055cf00 R13: 00007ffdda99102f R14: 00007fb75c9b5300 R15: 0000000000022000 INFO: task syz-executor.1:16057 blocked for more than 140 seconds. Not tainted 4.19.206-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.1 D28232 16057 14372 0x00000004 Call Trace: context_switch kernel/sched/core.c:2828 [inline] __schedule+0x80c/0x1f70 kernel/sched/core.c:3517 schedule+0x7f/0x1b0 kernel/sched/core.c:3561 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3619 __mutex_lock_common kernel/locking/mutex.c:1015 [inline] __mutex_lock+0x4ba/0x1190 kernel/locking/mutex.c:1083 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1098 hci_req_sync+0x32/0xa0 net/bluetooth/hci_request.c:275 hci_inquiry+0x593/0x750 net/bluetooth/hci_core.c:1310 hci_sock_ioctl+0x19e/0x680 net/bluetooth/hci_sock.c:1053 sock_do_ioctl+0xd9/0x240 net/socket.c:1015 sock_ioctl+0x281/0x500 net/socket.c:1135 vfs_ioctl fs/ioctl.c:46 [inline] file_ioctl fs/ioctl.c:501 [inline] do_vfs_ioctl+0x196/0x10c0 fs/ioctl.c:688 Bluetooth: hci6: command 0x0419 tx timeout ksys_ioctl+0x62/0x90 fs/ioctl.c:705 __do_sys_ioctl fs/ioctl.c:712 [inline] __se_sys_ioctl fs/ioctl.c:710 [inline] __x64_sys_ioctl+0x6e/0xb0 fs/ioctl.c:710 do_syscall_64+0xd0/0x4e0 arch/x86/entry/common.c:293 entry_SYSCALL_64_after_hwframe+0x49/0xbe RIP: 0033:0x465109 Code: Bad RIP value. RSP: 002b:00007fd8325c0188 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 RAX: ffffffffffffffda RBX: 000000000055cf00 RCX: 0000000000465109 RDX: 0000000020000200 RSI: 00000000800448f0 RDI: 0000000000000004 RBP: 00000000004af711 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 000000000055cf00 R13: 00007ffe2ce57baf R14: 00007fd8325c0300 R15: 0000000000022000 INFO: task syz-executor.1:16198 blocked for more than 140 seconds. Not tainted 4.19.206-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.1 D28328 16198 14372 0x00000004 Call Trace: context_switch kernel/sched/core.c:2828 [inline] __schedule+0x80c/0x1f70 kernel/sched/core.c:3517 schedule+0x7f/0x1b0 kernel/sched/core.c:3561 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3619 __mutex_lock_common kernel/locking/mutex.c:1015 [inline] __mutex_lock+0x4ba/0x1190 kernel/locking/mutex.c:1083 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1098 hci_req_sync+0x32/0xa0 net/bluetooth/hci_request.c:275 hci_inquiry+0x593/0x750 net/bluetooth/hci_core.c:1310 hci_sock_ioctl+0x19e/0x680 net/bluetooth/hci_sock.c:1053 sock_do_ioctl+0xd9/0x240 net/socket.c:1015 sock_ioctl+0x281/0x500 net/socket.c:1135 vfs_ioctl fs/ioctl.c:46 [inline] file_ioctl fs/ioctl.c:501 [inline] do_vfs_ioctl+0x196/0x10c0 fs/ioctl.c:688 ksys_ioctl+0x62/0x90 fs/ioctl.c:705 __do_sys_ioctl fs/ioctl.c:712 [inline] __se_sys_ioctl fs/ioctl.c:710 [inline] __x64_sys_ioctl+0x6e/0xb0 fs/ioctl.c:710 do_syscall_64+0xd0/0x4e0 arch/x86/entry/common.c:293 entry_SYSCALL_64_after_hwframe+0x49/0xbe RIP: 0033:0x465109 Code: Bad RIP value. RSP: 002b:00007fd83257e188 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 RAX: ffffffffffffffda RBX: 000000000055d040 RCX: 0000000000465109 RDX: 0000000020000200 RSI: 00000000800448f0 RDI: 0000000000000004 RBP: 00000000004af711 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 000000000055d040 R13: 00007ffe2ce57baf R14: 00007fd83257e300 R15: 0000000000022000 INFO: task syz-executor.3:16293 blocked for more than 140 seconds. Not tainted 4.19.206-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.3 D28232 16293 15980 0x00000004 Call Trace: context_switch kernel/sched/core.c:2828 [inline] __schedule+0x80c/0x1f70 kernel/sched/core.c:3517 schedule+0x7f/0x1b0 kernel/sched/core.c:3561 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3619 __mutex_lock_common kernel/locking/mutex.c:1015 [inline] __mutex_lock+0x4ba/0x1190 kernel/locking/mutex.c:1083 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1098 hci_req_sync+0x32/0xa0 net/bluetooth/hci_request.c:275 hci_inquiry+0x593/0x750 net/bluetooth/hci_core.c:1310 hci_sock_ioctl+0x19e/0x680 net/bluetooth/hci_sock.c:1053 sock_do_ioctl+0xd9/0x240 net/socket.c:1015 sock_ioctl+0x281/0x500 net/socket.c:1135 vfs_ioctl fs/ioctl.c:46 [inline] file_ioctl fs/ioctl.c:501 [inline] do_vfs_ioctl+0x196/0x10c0 fs/ioctl.c:688 ksys_ioctl+0x62/0x90 fs/ioctl.c:705 __do_sys_ioctl fs/ioctl.c:712 [inline] __se_sys_ioctl fs/ioctl.c:710 [inline] __x64_sys_ioctl+0x6e/0xb0 fs/ioctl.c:710 do_syscall_64+0xd0/0x4e0 arch/x86/entry/common.c:293 entry_SYSCALL_64_after_hwframe+0x49/0xbe RIP: 0033:0x465109 Code: Bad RIP value. RSP: 002b:00007f5023cc0188 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 RAX: ffffffffffffffda RBX: 000000000055cf00 RCX: 0000000000465109 RDX: 0000000020000200 RSI: 00000000800448f0 RDI: 0000000000000004 RBP: 00000000004af711 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 000000000055cf00 R13: 00007ffca95d5aef R14: 00007f5023cc0300 R15: 0000000000022000 INFO: task syz-executor.3:16299 blocked for more than 140 seconds. Not tainted 4.19.206-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.3 D29064 16299 15980 0x00000004 Call Trace: context_switch kernel/sched/core.c:2828 [inline] __schedule+0x80c/0x1f70 kernel/sched/core.c:3517 schedule+0x7f/0x1b0 kernel/sched/core.c:3561 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3619 __mutex_lock_common kernel/locking/mutex.c:1015 [inline] __mutex_lock+0x4ba/0x1190 kernel/locking/mutex.c:1083 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1098 hci_req_sync+0x32/0xa0 net/bluetooth/hci_request.c:275 hci_inquiry+0x593/0x750 net/bluetooth/hci_core.c:1310 hci_sock_ioctl+0x19e/0x680 net/bluetooth/hci_sock.c:1053 sock_do_ioctl+0xd9/0x240 net/socket.c:1015 sock_ioctl+0x281/0x500 net/socket.c:1135 vfs_ioctl fs/ioctl.c:46 [inline] file_ioctl fs/ioctl.c:501 [inline] do_vfs_ioctl+0x196/0x10c0 fs/ioctl.c:688 ksys_ioctl+0x62/0x90 fs/ioctl.c:705 __do_sys_ioctl fs/ioctl.c:712 [inline] __se_sys_ioctl fs/ioctl.c:710 [inline] __x64_sys_ioctl+0x6e/0xb0 fs/ioctl.c:710 do_syscall_64+0xd0/0x4e0 arch/x86/entry/common.c:293 entry_SYSCALL_64_after_hwframe+0x49/0xbe RIP: 0033:0x465109 Code: Bad RIP value. RSP: 002b:00007f5023c7e188 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 RAX: ffffffffffffffda RBX: 000000000055d040 RCX: 0000000000465109 RDX: 0000000020000200 RSI: 00000000800448f0 RDI: 0000000000000004 RBP: 00000000004af711 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 000000000055d040 R13: 00007ffca95d5aef R14: 00007f5023c7e300 R15: 0000000000022000 Showing all locks held in the system: 2 locks held by ksoftirqd/0/9: #0: 000000000cc516ec (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1824 [inline] #0: 000000000cc516ec (&rq->lock){-.-.}, at: __schedule+0x1f6/0x1f70 kernel/sched/core.c:3455 #1: 00000000d83de138 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline] #1: 00000000d83de138 (rcu_read_lock){....}, at: update_curr+0x2cf/0x870 kernel/sched/fair.c:857 1 lock held by khungtaskd/1095: #0: 00000000d83de138 (rcu_read_lock){....}, at: debug_show_all_locks+0x5b/0x27a kernel/locking/lockdep.c:4443 1 lock held by syz-executor.0/16050: #0: 00000000bf866d71 (&hdev->req_lock){+.+.}, at: hci_req_sync+0x32/0xa0 net/bluetooth/hci_request.c:275 1 lock held by syz-executor.4/16038: #0: 00000000bf866d71 (&hdev->req_lock){+.+.}, at: hci_req_sync+0x32/0xa0 net/bluetooth/hci_request.c:275 1 lock held by syz-executor.1/16057: #0: 00000000bf866d71 (&hdev->req_lock){+.+.}, at: hci_req_sync+0x32/0xa0 net/bluetooth/hci_request.c:275 1 lock held by syz-executor.1/16198: #0: 00000000bf866d71 (&hdev->req_lock){+.+.}, at: hci_req_sync+0x32/0xa0 net/bluetooth/hci_request.c:275 1 lock held by syz-executor.3/16293: #0: 00000000bf866d71 (&hdev->req_lock){+.+.}, at: hci_req_sync+0x32/0xa0 net/bluetooth/hci_request.c:275 1 lock held by syz-executor.3/16299: #0: 00000000bf866d71 (&hdev->req_lock){+.+.}, at: hci_req_sync+0x32/0xa0 net/bluetooth/hci_request.c:275 1 lock held by syz-executor951/16338: #0: 00000000bf866d71 (&hdev->req_lock){+.+.}, at: hci_req_sync+0x32/0xa0 net/bluetooth/hci_request.c:275 ============================================= NMI backtrace for cpu 1 CPU: 1 PID: 1095 Comm: khungtaskd Not tainted 4.19.206-syzkaller #0 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 Call Trace: __dump_stack lib/dump_stack.c:77 [inline] dump_stack+0x17c/0x226 lib/dump_stack.c:118 nmi_cpu_backtrace.cold.0+0x3c/0x78 lib/nmi_backtrace.c:101 nmi_trigger_cpumask_backtrace+0xf5/0x120 lib/nmi_backtrace.c:62 arch_trigger_cpumask_backtrace+0x14/0x20 arch/x86/kernel/apic/hw_nmi.c:38 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline] check_hung_uninterruptible_tasks kernel/hung_task.c:203 [inline] watchdog+0x5c3/0xb40 kernel/hung_task.c:287 kthread+0x347/0x410 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: 2779 Comm: kworker/u4:4 Not tainted 4.19.206-syzkaller #0 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 Workqueue: bat_events batadv_purge_orig RIP: 0010:lock_release+0x54/0x840 kernel/locking/lockdep.c:3917 Code: 89 95 70 ff ff ff 65 4c 8b 2c 25 80 ee 01 00 48 8d 14 03 48 c7 45 80 2f 4d 1b 88 49 8d bd 84 08 00 00 48 c7 45 88 c0 af 4a 81 <48> c7 85 78 ff ff ff b3 8a b5 41 c7 02 f1 f1 f1 f1 c7 42 04 04 f2 RSP: 0018:ffff8881e75f7b78 EFLAGS: 00000296 RAX: dffffc0000000000 RBX: 1ffff1103cebef72 RCX: ffffffff814b4870 RDX: ffffed103cebef72 RSI: 0000000000000001 RDI: ffff8881e75eca84 RBP: ffff8881e75f7c18 R08: ffffed1039550a4e R09: ffffed1039550a4d R10: ffffed1039550a4d R11: ffff8881caa8526b R12: ffff8881caa85280 R13: ffff8881e75ec200 R14: ffff8881e53b6c00 R15: ffff8881cd4aa6b0 FS: 0000000000000000(0000) GS:ffff8881f6800000(0000) knlGS:0000000000000000 CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 CR2: 00007f53bb1a8000 CR3: 000000000846d003 CR4: 00000000001606f0 DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 Call Trace: __raw_spin_unlock_bh include/linux/spinlock_api_smp.h:174 [inline] _raw_spin_unlock_bh+0x1a/0x40 kernel/locking/spinlock.c:200 spin_unlock_bh include/linux/spinlock.h:374 [inline] batadv_purge_orig_ref+0x61a/0xf80 net/batman-adv/originator.c:1379 batadv_purge_orig+0x14/0x60 net/batman-adv/originator.c:1392 process_one_work+0x7b9/0x15a0 kernel/workqueue.c:2153 worker_thread+0x85/0xb60 kernel/workqueue.c:2296 kthread+0x347/0x410 kernel/kthread.c:259 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415 ---------------- Code disassembly (best guess): 0: 89 95 70 ff ff ff mov %edx,-0x90(%rbp) 6: 65 4c 8b 2c 25 80 ee mov %gs:0x1ee80,%r13 d: 01 00 f: 48 8d 14 03 lea (%rbx,%rax,1),%rdx 13: 48 c7 45 80 2f 4d 1b movq $0xffffffff881b4d2f,-0x80(%rbp) 1a: 88 1b: 49 8d bd 84 08 00 00 lea 0x884(%r13),%rdi 22: 48 c7 45 88 c0 af 4a movq $0xffffffff814aafc0,-0x78(%rbp) 29: 81 * 2a: 48 c7 85 78 ff ff ff movq $0x41b58ab3,-0x88(%rbp) <-- trapping instruction 31: b3 8a b5 41 35: c7 02 f1 f1 f1 f1 movl $0xf1f1f1f1,(%rdx) 3b: c7 .byte 0xc7 3c: 42 04 04 rex.X add $0x4,%al 3f: f2 repnz