Re: [syzbot] [bluetooth?] KASAN: slab-use-after-free Read in hci_send_acl

From: syzbot
Date: Fri Aug 25 2023 - 08:57:45 EST


Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:
INFO: task hung in l2cap_chan_timeout

INFO: task kworker/0:0:8 blocked for more than 143 seconds.
Not tainted 6.5.0-rc6-next-20230818-syzkaller-dirty #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/0:0 state:D stack:26488 pid:8 ppid:2 flags:0x00004000
Workqueue: events l2cap_chan_timeout
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5382 [inline]
__schedule+0xee1/0x59f0 kernel/sched/core.c:6695
schedule+0xe7/0x1b0 kernel/sched/core.c:6771
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6830
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0x967/0x1340 kernel/locking/mutex.c:747
l2cap_chan_timeout+0x68/0x2f0 net/bluetooth/l2cap_core.c:438
process_one_work+0x887/0x15d0 kernel/workqueue.c:2630
process_scheduled_works kernel/workqueue.c:2703 [inline]
worker_thread+0x8bb/0x1290 kernel/workqueue.c:2784
kthread+0x33a/0x430 kernel/kthread.c:388
ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:304
</TASK>
INFO: task kworker/0:1:9 blocked for more than 143 seconds.
Not tainted 6.5.0-rc6-next-20230818-syzkaller-dirty #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/0:1 state:D stack:28784 pid:9 ppid:2 flags:0x00004000
Workqueue: events l2cap_chan_timeout
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5382 [inline]
__schedule+0xee1/0x59f0 kernel/sched/core.c:6695
schedule+0xe7/0x1b0 kernel/sched/core.c:6771
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6830
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0x967/0x1340 kernel/locking/mutex.c:747
l2cap_chan_timeout+0x68/0x2f0 net/bluetooth/l2cap_core.c:438
process_one_work+0x887/0x15d0 kernel/workqueue.c:2630
process_scheduled_works kernel/workqueue.c:2703 [inline]
worker_thread+0x8bb/0x1290 kernel/workqueue.c:2784
kthread+0x33a/0x430 kernel/kthread.c:388
ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:304
</TASK>
INFO: task kworker/1:0:23 blocked for more than 143 seconds.
Not tainted 6.5.0-rc6-next-20230818-syzkaller-dirty #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:0 state:D stack:25448 pid:23 ppid:2 flags:0x00004000
Workqueue: events l2cap_chan_timeout
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5382 [inline]
__schedule+0xee1/0x59f0 kernel/sched/core.c:6695
schedule+0xe7/0x1b0 kernel/sched/core.c:6771
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6830
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0x967/0x1340 kernel/locking/mutex.c:747
l2cap_chan_timeout+0x68/0x2f0 net/bluetooth/l2cap_core.c:438
process_one_work+0x887/0x15d0 kernel/workqueue.c:2630
process_scheduled_works kernel/workqueue.c:2703 [inline]
worker_thread+0x8bb/0x1290 kernel/workqueue.c:2784
kthread+0x33a/0x430 kernel/kthread.c:388
ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:304
</TASK>
INFO: task kworker/1:1:27 blocked for more than 143 seconds.
Not tainted 6.5.0-rc6-next-20230818-syzkaller-dirty #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:1 state:D stack:25880 pid:27 ppid:2 flags:0x00004000
Workqueue: events l2cap_chan_timeout
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5382 [inline]
__schedule+0xee1/0x59f0 kernel/sched/core.c:6695
schedule+0xe7/0x1b0 kernel/sched/core.c:6771
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6830
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0x967/0x1340 kernel/locking/mutex.c:747
l2cap_chan_timeout+0x68/0x2f0 net/bluetooth/l2cap_core.c:438
process_one_work+0x887/0x15d0 kernel/workqueue.c:2630
process_scheduled_works kernel/workqueue.c:2703 [inline]
worker_thread+0x8bb/0x1290 kernel/workqueue.c:2784
kthread+0x33a/0x430 kernel/kthread.c:388
ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:304
</TASK>
INFO: task kworker/u5:0:50 blocked for more than 144 seconds.
Not tainted 6.5.0-rc6-next-20230818-syzkaller-dirty #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/u5:0 state:D stack:27704 pid:50 ppid:2 flags:0x00004000
Workqueue: hci0 hci_cmd_sync_work
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5382 [inline]
__schedule+0xee1/0x59f0 kernel/sched/core.c:6695
schedule+0xe7/0x1b0 kernel/sched/core.c:6771
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6830
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0x967/0x1340 kernel/locking/mutex.c:747
l2cap_chan_del+0x2b3/0xaa0 net/bluetooth/l2cap_core.c:659
l2cap_conn_del+0x3ce/0x870 net/bluetooth/l2cap_core.c:1918
l2cap_connect_cfm+0xa10/0xf90 net/bluetooth/l2cap_core.c:8232
hci_connect_cfm include/net/bluetooth/hci_core.h:1933 [inline]
hci_conn_failed+0x196/0x320 net/bluetooth/hci_conn.c:1235
hci_abort_conn_sync+0xacb/0xe20 net/bluetooth/hci_sync.c:5432
abort_conn_sync+0x18e/0x3a0 net/bluetooth/hci_conn.c:2878
hci_cmd_sync_work+0x1a4/0x3c0 net/bluetooth/hci_sync.c:306
process_one_work+0x887/0x15d0 kernel/workqueue.c:2630
process_scheduled_works kernel/workqueue.c:2703 [inline]
worker_thread+0x8bb/0x1290 kernel/workqueue.c:2784
kthread+0x33a/0x430 kernel/kthread.c:388
ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:304
</TASK>
INFO: task kworker/0:2:54 blocked for more than 144 seconds.
Not tainted 6.5.0-rc6-next-20230818-syzkaller-dirty #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/0:2 state:D stack:25568 pid:54 ppid:2 flags:0x00004000
Workqueue: events l2cap_chan_timeout
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5382 [inline]
__schedule+0xee1/0x59f0 kernel/sched/core.c:6695
schedule+0xe7/0x1b0 kernel/sched/core.c:6771
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6830
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0x967/0x1340 kernel/locking/mutex.c:747
l2cap_chan_del+0x2b3/0xaa0 net/bluetooth/l2cap_core.c:659
l2cap_chan_close+0xff/0xa20 net/bluetooth/l2cap_core.c:844
l2cap_chan_timeout+0x17d/0x2f0 net/bluetooth/l2cap_core.c:452
process_one_work+0x887/0x15d0 kernel/workqueue.c:2630
process_scheduled_works kernel/workqueue.c:2703 [inline]
worker_thread+0x8bb/0x1290 kernel/workqueue.c:2784
kthread+0x33a/0x430 kernel/kthread.c:388
ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:304
</TASK>
INFO: task kworker/1:2:780 blocked for more than 144 seconds.
Not tainted 6.5.0-rc6-next-20230818-syzkaller-dirty #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:2 state:D stack:26504 pid:780 ppid:2 flags:0x00004000
Workqueue: events l2cap_chan_timeout
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5382 [inline]
__schedule+0xee1/0x59f0 kernel/sched/core.c:6695
schedule+0xe7/0x1b0 kernel/sched/core.c:6771
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6830
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0x967/0x1340 kernel/locking/mutex.c:747
l2cap_chan_timeout+0x68/0x2f0 net/bluetooth/l2cap_core.c:438
process_one_work+0x887/0x15d0 kernel/workqueue.c:2630
process_scheduled_works kernel/workqueue.c:2703 [inline]
worker_thread+0x8bb/0x1290 kernel/workqueue.c:2784
kthread+0x33a/0x430 kernel/kthread.c:388
ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:304
</TASK>
INFO: task kworker/1:3:4456 blocked for more than 144 seconds.
Not tainted 6.5.0-rc6-next-20230818-syzkaller-dirty #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:3 state:D stack:28128 pid:4456 ppid:2 flags:0x00004000
Workqueue: events l2cap_chan_timeout
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5382 [inline]
__schedule+0xee1/0x59f0 kernel/sched/core.c:6695
schedule+0xe7/0x1b0 kernel/sched/core.c:6771
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6830
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0x967/0x1340 kernel/locking/mutex.c:747
l2cap_chan_timeout+0x68/0x2f0 net/bluetooth/l2cap_core.c:438
process_one_work+0x887/0x15d0 kernel/workqueue.c:2630
process_scheduled_works kernel/workqueue.c:2703 [inline]
worker_thread+0x8bb/0x1290 kernel/workqueue.c:2784
kthread+0x33a/0x430 kernel/kthread.c:388
ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:304
</TASK>
INFO: task kworker/1:4:5053 blocked for more than 145 seconds.
Not tainted 6.5.0-rc6-next-20230818-syzkaller-dirty #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:4 state:D stack:25112 pid:5053 ppid:2 flags:0x00004000
Workqueue: events l2cap_chan_timeout
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5382 [inline]
__schedule+0xee1/0x59f0 kernel/sched/core.c:6695
schedule+0xe7/0x1b0 kernel/sched/core.c:6771
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6830
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0x967/0x1340 kernel/locking/mutex.c:747
l2cap_chan_timeout+0x68/0x2f0 net/bluetooth/l2cap_core.c:438
process_one_work+0x887/0x15d0 kernel/workqueue.c:2630
process_scheduled_works kernel/workqueue.c:2703 [inline]
worker_thread+0x8bb/0x1290 kernel/workqueue.c:2784
kthread+0x33a/0x430 kernel/kthread.c:388
ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:304
</TASK>
INFO: task kworker/0:4:5059 blocked for more than 145 seconds.
Not tainted 6.5.0-rc6-next-20230818-syzkaller-dirty #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/0:4 state:D stack:27920 pid:5059 ppid:2 flags:0x00004000
Workqueue: events l2cap_chan_timeout
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5382 [inline]
__schedule+0xee1/0x59f0 kernel/sched/core.c:6695
schedule+0xe7/0x1b0 kernel/sched/core.c:6771
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6830
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0x967/0x1340 kernel/locking/mutex.c:747
l2cap_chan_timeout+0x68/0x2f0 net/bluetooth/l2cap_core.c:438
process_one_work+0x887/0x15d0 kernel/workqueue.c:2630
process_scheduled_works kernel/workqueue.c:2703 [inline]
worker_thread+0x8bb/0x1290 kernel/workqueue.c:2784
kthread+0x33a/0x430 kernel/kthread.c:388
ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:304
</TASK>
Future hung task reports are suppressed, see sysctl kernel.hung_task_warnings
INFO: lockdep is turned off.
NMI backtrace for cpu 0
CPU: 0 PID: 29 Comm: khungtaskd Not tainted 6.5.0-rc6-next-20230818-syzkaller-dirty #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 07/26/2023
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0xd9/0x1b0 lib/dump_stack.c:106
nmi_cpu_backtrace+0x277/0x380 lib/nmi_backtrace.c:113
nmi_trigger_cpumask_backtrace+0x299/0x300 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:160 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:222 [inline]
watchdog+0xfac/0x1230 kernel/hung_task.c:379
kthread+0x33a/0x430 kernel/kthread.c:388
ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:304
</TASK>
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1 skipped: idling at native_safe_halt arch/x86/include/asm/irqflags.h:48 [inline]
NMI backtrace for cpu 1 skipped: idling at arch_safe_halt arch/x86/include/asm/irqflags.h:86 [inline]
NMI backtrace for cpu 1 skipped: idling at acpi_safe_halt+0x1b/0x20 drivers/acpi/processor_idle.c:112


Tested on:

commit: 7271b2a5 Add linux-next specific files for 20230818
git tree: https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git
console output: https://syzkaller.appspot.com/x/log.txt?x=109b2797a80000
kernel config: https://syzkaller.appspot.com/x/.config?x=1936af09cdef7dd6
dashboard link: https://syzkaller.appspot.com/bug?extid=a0c80b06ae2cb8895bc4
compiler: gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils for Debian) 2.40
patch: https://syzkaller.appspot.com/x/patch.diff?x=146ec7cfa80000