bisecting fixing commit since f6d5cb9e2c06f7d583dd9f4f7cca21d13d78c32a building syzkaller on 816e0689d7d9d8321f8bf360740f0e516aee15ca testing commit f6d5cb9e2c06f7d583dd9f4f7cca21d13d78c32a with gcc (GCC) 8.1.0 kernel signature: 975e2c8b3c4cd127f306afba31b580f95a8ce105a4e57838c59b90542c667e43 run #0: crashed: WARNING: ODEBUG bug in bt_host_release run #1: crashed: WARNING: ODEBUG bug in bt_host_release run #2: crashed: WARNING: ODEBUG bug in bt_host_release run #3: crashed: WARNING: ODEBUG bug in bt_host_release run #4: crashed: WARNING: ODEBUG bug in bt_host_release run #5: crashed: WARNING: ODEBUG bug in bt_host_release run #6: crashed: KASAN: use-after-free Read in __queue_work run #7: crashed: WARNING: ODEBUG bug in bt_host_release run #8: OK run #9: crashed: WARNING: ODEBUG bug in bt_host_release testing current HEAD 0c88e405c97ed1828443b67891e6d4bb6e56cd4e testing commit 0c88e405c97ed1828443b67891e6d4bb6e56cd4e with gcc (GCC) 8.1.0 kernel signature: ff248952afbfb023addacf517939afa6fe91905b810713e9ddd03bd99f6649e6 run #0: crashed: WARNING: ODEBUG bug in bt_host_release run #1: crashed: INFO: task hung in hci_req_sync run #2: crashed: WARNING: ODEBUG bug in bt_host_release run #3: crashed: INFO: task hung in hci_req_sync run #4: OK run #5: OK run #6: OK run #7: OK run #8: OK run #9: OK reproducer seems to be flaky Reproducer flagged being flaky revisions tested: 2, total time: 39m18.431015033s (build: 17m35.535201287s, test: 20m47.585625777s) the crash still happens on HEAD commit msg: Linux 4.19.160 crash: INFO: task hung in hci_req_sync Bluetooth: hci1: command 0x0401 tx timeout Bluetooth: hci1: command 0x0401 tx timeout Bluetooth: hci1: command 0x0401 tx timeout Bluetooth: hci1: command 0x0401 tx timeout Bluetooth: hci1: command 0x0401 tx timeout INFO: task syz-executor.4:22832 blocked for more than 140 seconds. Not tainted 4.19.160-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.4 D28232 22832 16862 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:1002 [inline] __mutex_lock+0x4c3/0x1200 kernel/locking/mutex.c:1072 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1087 hci_req_sync+0x5b/0xb0 net/bluetooth/hci_request.c:278 hci_inquiry+0x58a/0x760 net/bluetooth/hci_core.c:1310 hci_sock_ioctl+0x19e/0x600 net/bluetooth/hci_sock.c:1048 sock_do_ioctl+0xd9/0x230 net/socket.c:950 sock_ioctl+0x281/0x500 net/socket.c:1074 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:0x45d5b9 Code: Bad RIP value. RSP: 002b:00007f5f7728fc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 RAX: ffffffffffffffda RBX: 000000000000f2c0 RCX: 000000000045d5b9 RDX: 0000000020000200 RSI: 00000000800448f0 RDI: 0000000000000004 RBP: 000000000118cf80 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118cf4c R13: 00007fff0543702f R14: 00007f5f772909c0 R15: 000000000118cf4c INFO: task syz-executor.1:22833 blocked for more than 140 seconds. Not tainted 4.19.160-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.1 D28232 22833 14638 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:1002 [inline] __mutex_lock+0x4c3/0x1200 kernel/locking/mutex.c:1072 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1087 hci_req_sync+0x5b/0xb0 net/bluetooth/hci_request.c:278 hci_inquiry+0x58a/0x760 net/bluetooth/hci_core.c:1310 hci_sock_ioctl+0x19e/0x600 net/bluetooth/hci_sock.c:1048 sock_do_ioctl+0xd9/0x230 net/socket.c:950 sock_ioctl+0x281/0x500 net/socket.c:1074 vfs_ioctl fs/ioctl.c:46 [inline] file_ioctl fs/ioctl.c:501 [inline] do_vfs_ioctl+0x196/0x10c0 fs/ioctl.c:688 Bluetooth: hci1: command 0x0401 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:0x45d5b9 Code: Bad RIP value. RSP: 002b:00007f44ead2bc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 RAX: ffffffffffffffda RBX: 000000000000f2c0 RCX: 000000000045d5b9 RDX: 0000000020000200 RSI: 00000000800448f0 RDI: 0000000000000004 RBP: 000000000118cf80 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118cf4c R13: 00007ffcc75d6e0f R14: 00007f44ead2c9c0 R15: 000000000118cf4c INFO: task syz-executor.0:22834 blocked for more than 140 seconds. Not tainted 4.19.160-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.0 D28232 22834 18505 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:1002 [inline] __mutex_lock+0x4c3/0x1200 kernel/locking/mutex.c:1072 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1087 hci_req_sync+0x5b/0xb0 net/bluetooth/hci_request.c:278 hci_inquiry+0x58a/0x760 net/bluetooth/hci_core.c:1310 hci_sock_ioctl+0x19e/0x600 net/bluetooth/hci_sock.c:1048 sock_do_ioctl+0xd9/0x230 net/socket.c:950 sock_ioctl+0x281/0x500 net/socket.c:1074 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:0x45d5b9 Code: Bad RIP value. RSP: 002b:00007f6ea79c5c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 RAX: ffffffffffffffda RBX: 000000000000f2c0 RCX: 000000000045d5b9 RDX: 0000000020000200 RSI: 00000000800448f0 RDI: 0000000000000004 RBP: 000000000118cf80 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118cf4c R13: 00007ffc9af3049f R14: 00007f6ea79c69c0 R15: 000000000118cf4c INFO: task syz-executor.3:23084 blocked for more than 140 seconds. Not tainted 4.19.160-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.3 D28232 23084 22805 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:1002 [inline] __mutex_lock+0x4c3/0x1200 kernel/locking/mutex.c:1072 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1087 hci_req_sync+0x5b/0xb0 net/bluetooth/hci_request.c:278 hci_inquiry+0x58a/0x760 net/bluetooth/hci_core.c:1310 hci_sock_ioctl+0x19e/0x600 net/bluetooth/hci_sock.c:1048 sock_do_ioctl+0xd9/0x230 net/socket.c:950 sock_ioctl+0x281/0x500 net/socket.c:1074 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:0x45d5b9 Code: Bad RIP value. RSP: 002b:00007f22679bfc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 RAX: ffffffffffffffda RBX: 000000000000f2c0 RCX: 000000000045d5b9 RDX: 0000000020000200 RSI: 00000000800448f0 RDI: 0000000000000004 RBP: 000000000118cf80 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118cf4c R13: 00007ffec9a5cc1f R14: 00007f22679c09c0 R15: 000000000118cf4c INFO: task syz-executor.3:23088 blocked for more than 140 seconds. Not tainted 4.19.160-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.3 D28824 23088 22805 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:1002 [inline] __mutex_lock+0x4c3/0x1200 kernel/locking/mutex.c:1072 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1087 hci_req_sync+0x5b/0xb0 net/bluetooth/hci_request.c:278 hci_inquiry+0x58a/0x760 net/bluetooth/hci_core.c:1310 hci_sock_ioctl+0x19e/0x600 net/bluetooth/hci_sock.c:1048 sock_do_ioctl+0xd9/0x230 net/socket.c:950 sock_ioctl+0x281/0x500 net/socket.c:1074 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:0x45d5b9 Code: Bad RIP value. RSP: 002b:00007f226797dc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 RAX: ffffffffffffffda RBX: 000000000000f2c0 RCX: 000000000045d5b9 RDX: 0000000020000200 RSI: 00000000800448f0 RDI: 0000000000000004 RBP: 000000000118d0c0 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118d08c R13: 00007ffec9a5cc1f R14: 00007f226797e9c0 R15: 000000000118d08c Showing all locks held in the system: 1 lock held by khungtaskd/1092: #0: 00000000b0512f61 (rcu_read_lock){....}, at: debug_show_all_locks+0x5b/0x27a kernel/locking/lockdep.c:4442 1 lock held by in:imklog/6118: #0: 0000000078039b7d (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xa7/0xd0 fs/file.c:767 1 lock held by syz-executor.2/22821: #0: 000000003516baaf (&hdev->req_lock){+.+.}, at: hci_req_sync+0x5b/0xb0 net/bluetooth/hci_request.c:278 1 lock held by syz-executor.4/22832: #0: 000000003516baaf (&hdev->req_lock){+.+.}, at: hci_req_sync+0x5b/0xb0 net/bluetooth/hci_request.c:278 1 lock held by syz-executor.1/22833: #0: 000000003516baaf (&hdev->req_lock){+.+.}, at: hci_req_sync+0x5b/0xb0 net/bluetooth/hci_request.c:278 1 lock held by syz-executor.0/22834: #0: 000000003516baaf (&hdev->req_lock){+.+.}, at: hci_req_sync+0x5b/0xb0 net/bluetooth/hci_request.c:278 1 lock held by syz-executor.3/23084: #0: 000000003516baaf (&hdev->req_lock){+.+.}, at: hci_req_sync+0x5b/0xb0 net/bluetooth/hci_request.c:278 1 lock held by syz-executor.3/23088: #0: 000000003516baaf (&hdev->req_lock){+.+.}, at: hci_req_sync+0x5b/0xb0 net/bluetooth/hci_request.c:278 ============================================= NMI backtrace for cpu 1 CPU: 1 PID: 1092 Comm: khungtaskd Not tainted 4.19.160-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/0x22a lib/dump_stack.c:118 nmi_cpu_backtrace.cold.0+0x3c/0x78 lib/nmi_backtrace.c:101 nmi_trigger_cpumask_backtrace+0xf5/0x119 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 skipped: idling at native_safe_halt+0x12/0x20 arch/x86/include/asm/irqflags.h:60