Re: [syzbot] KASAN: use-after-free Write in sco_sock_timeout

From: Desmond Cheong Zhi Xi
Date: Fri Aug 27 2021 - 03:58:42 EST


On 27/8/21 9:19 am, Hillf Danton wrote:
On Thu, 26 Aug 2021 09:29:24 -0700
syzbot found the following issue on:

HEAD commit: e3f30ab28ac8 Merge branch 'pktgen-samples-next'
git tree: net-next
console output: https://syzkaller.appspot.com/x/log.txt?x=13249c96300000
kernel config: https://syzkaller.appspot.com/x/.config?x=ef482942966bf763
dashboard link: https://syzkaller.appspot.com/bug?extid=2bef95d3ab4daa10155b
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.1
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=16a29ea9300000

The issue was bisected to:

commit e1dee2c1de2b4dd00eb44004a4bda6326ed07b59
Author: Desmond Cheong Zhi Xi <desmondcheongzx@xxxxxxxxx>
Date: Tue Aug 10 04:14:10 2021 +0000

Bluetooth: fix repeated calls to sco_sock_kill

bisection log: https://syzkaller.appspot.com/x/bisect.txt?x=15030c91300000
final oops: https://syzkaller.appspot.com/x/report.txt?x=17030c91300000
console output: https://syzkaller.appspot.com/x/log.txt?x=13030c91300000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+2bef95d3ab4daa10155b@xxxxxxxxxxxxxxxxxxxxxxxxx
Fixes: e1dee2c1de2b ("Bluetooth: fix repeated calls to sco_sock_kill")

==================================================================
BUG: KASAN: use-after-free in instrument_atomic_read_write include/linux/instrumented.h:101 [inline]
BUG: KASAN: use-after-free in atomic_fetch_add_relaxed include/asm-generic/atomic-instrumented.h:111 [inline]
BUG: KASAN: use-after-free in __refcount_add include/linux/refcount.h:193 [inline]
BUG: KASAN: use-after-free in __refcount_inc include/linux/refcount.h:250 [inline]
BUG: KASAN: use-after-free in refcount_inc include/linux/refcount.h:267 [inline]
BUG: KASAN: use-after-free in sock_hold include/net/sock.h:702 [inline]
BUG: KASAN: use-after-free in sco_sock_timeout+0x64/0x290 net/bluetooth/sco.c:88
Write of size 4 at addr ffff888034b46080 by task kworker/1:0/20

CPU: 1 PID: 20 Comm: kworker/1:0 Not tainted 5.14.0-rc6-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: events sco_sock_timeout
Call Trace:
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:105
print_address_description.constprop.0.cold+0x6c/0x309 mm/kasan/report.c:233
__kasan_report mm/kasan/report.c:419 [inline]
kasan_report.cold+0x83/0xdf mm/kasan/report.c:436
check_region_inline mm/kasan/generic.c:183 [inline]
kasan_check_range+0x13d/0x180 mm/kasan/generic.c:189
instrument_atomic_read_write include/linux/instrumented.h:101 [inline]
atomic_fetch_add_relaxed include/asm-generic/atomic-instrumented.h:111 [inline]
__refcount_add include/linux/refcount.h:193 [inline]
__refcount_inc include/linux/refcount.h:250 [inline]
refcount_inc include/linux/refcount.h:267 [inline]
sock_hold include/net/sock.h:702 [inline]
sco_sock_timeout+0x64/0x290 net/bluetooth/sco.c:88
process_one_work+0x98d/0x1630 kernel/workqueue.c:2276
worker_thread+0x658/0x11f0 kernel/workqueue.c:2422
kthread+0x3e5/0x4d0 kernel/kthread.c:319
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295

Allocated by task 4872:
kasan_save_stack+0x1b/0x40 mm/kasan/common.c:38
kasan_set_track mm/kasan/common.c:46 [inline]
set_alloc_info mm/kasan/common.c:434 [inline]
____kasan_kmalloc mm/kasan/common.c:513 [inline]
____kasan_kmalloc mm/kasan/common.c:472 [inline]
__kasan_kmalloc+0x9b/0xd0 mm/kasan/common.c:522
kmalloc include/linux/slab.h:596 [inline]
sk_prot_alloc+0x110/0x290 net/core/sock.c:1822
sk_alloc+0x32/0xbc0 net/core/sock.c:1875
__netlink_create+0x63/0x2f0 net/netlink/af_netlink.c:640
netlink_create+0x3ad/0x5e0 net/netlink/af_netlink.c:703
__sock_create+0x353/0x790 net/socket.c:1461
sock_create net/socket.c:1512 [inline]
__sys_socket+0xef/0x200 net/socket.c:1554
__do_sys_socket net/socket.c:1563 [inline]
__se_sys_socket net/socket.c:1561 [inline]
__x64_sys_socket+0x6f/0xb0 net/socket.c:1561
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae

Freed by task 0:
kasan_save_stack+0x1b/0x40 mm/kasan/common.c:38
kasan_set_track+0x1c/0x30 mm/kasan/common.c:46
kasan_set_free_info+0x20/0x30 mm/kasan/generic.c:360
____kasan_slab_free mm/kasan/common.c:366 [inline]
____kasan_slab_free mm/kasan/common.c:328 [inline]
__kasan_slab_free+0xfb/0x130 mm/kasan/common.c:374
kasan_slab_free include/linux/kasan.h:230 [inline]
slab_free_hook mm/slub.c:1628 [inline]
slab_free_freelist_hook+0xdf/0x240 mm/slub.c:1653
slab_free mm/slub.c:3213 [inline]
kfree+0xe4/0x540 mm/slub.c:4267
sk_prot_free net/core/sock.c:1858 [inline]
__sk_destruct+0x6a8/0x900 net/core/sock.c:1943
sk_destruct+0xbd/0xe0 net/core/sock.c:1958
__sk_free+0xef/0x3d0 net/core/sock.c:1969
sk_free+0x78/0xa0 net/core/sock.c:1980
deferred_put_nlk_sk+0x151/0x2f0 net/netlink/af_netlink.c:740
rcu_do_batch kernel/rcu/tree.c:2550 [inline]
rcu_core+0x7ab/0x1380 kernel/rcu/tree.c:2785
__do_softirq+0x29b/0x9c2 kernel/softirq.c:558

Last potentially related work creation:
kasan_save_stack+0x1b/0x40 mm/kasan/common.c:38
kasan_record_aux_stack+0xe5/0x110 mm/kasan/generic.c:348
__call_rcu kernel/rcu/tree.c:3029 [inline]
call_rcu+0xb1/0x750 kernel/rcu/tree.c:3109
netlink_release+0xdd4/0x1dd0 net/netlink/af_netlink.c:812
__sock_release+0xcd/0x280 net/socket.c:649
sock_close+0x18/0x20 net/socket.c:1311
__fput+0x288/0x920 fs/file_table.c:280
task_work_run+0xdd/0x1a0 kernel/task_work.c:164
exit_task_work include/linux/task_work.h:32 [inline]
do_exit+0xbd4/0x2a60 kernel/exit.c:825
do_group_exit+0x125/0x310 kernel/exit.c:922
__do_sys_exit_group kernel/exit.c:933 [inline]
__se_sys_exit_group kernel/exit.c:931 [inline]
__x64_sys_exit_group+0x3a/0x50 kernel/exit.c:931
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae

Second to last potentially related work creation:
kasan_save_stack+0x1b/0x40 mm/kasan/common.c:38
kasan_record_aux_stack+0xe5/0x110 mm/kasan/generic.c:348
__call_rcu kernel/rcu/tree.c:3029 [inline]
call_rcu+0xb1/0x750 kernel/rcu/tree.c:3109
netlink_release+0xdd4/0x1dd0 net/netlink/af_netlink.c:812
__sock_release+0xcd/0x280 net/socket.c:649
sock_close+0x18/0x20 net/socket.c:1311
__fput+0x288/0x920 fs/file_table.c:280
task_work_run+0xdd/0x1a0 kernel/task_work.c:164
exit_task_work include/linux/task_work.h:32 [inline]
do_exit+0xbd4/0x2a60 kernel/exit.c:825
do_group_exit+0x125/0x310 kernel/exit.c:922
__do_sys_exit_group kernel/exit.c:933 [inline]
__se_sys_exit_group kernel/exit.c:931 [inline]
__x64_sys_exit_group+0x3a/0x50 kernel/exit.c:931
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae

The buggy address belongs to the object at ffff888034b46000
which belongs to the cache kmalloc-2k of size 2048
The buggy address is located 128 bytes inside of
2048-byte region [ffff888034b46000, ffff888034b46800)
The buggy address belongs to the page:
page:ffffea0000d2d000 refcount:1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x34b40
head:ffffea0000d2d000 order:3 compound_mapcount:0 compound_pincount:0
flags: 0xfff00000010200(slab|head|node=0|zone=1|lastcpupid=0x7ff)
raw: 00fff00000010200 ffffea0000c37a00 0000000200000002 ffff888010c42000
raw: 0000000000000000 0000000000080008 00000001ffffffff 0000000000000000
page dumped because: kasan: bad access detected
page_owner tracks the page as allocated
page last allocated via order 3, migratetype Unmovable, gfp_mask 0xd20c0(__GFP_IO|__GFP_FS|__GFP_NOWARN|__GFP_NORETRY|__GFP_COMP|__GFP_NOMEMALLOC), pid 8634, ts 417197903424, free_ts 417180376519
prep_new_page mm/page_alloc.c:2436 [inline]
get_page_from_freelist+0xa72/0x2f80 mm/page_alloc.c:4169
__alloc_pages+0x1b2/0x500 mm/page_alloc.c:5391
alloc_pages+0x18c/0x2a0 mm/mempolicy.c:2244
alloc_slab_page mm/slub.c:1691 [inline]
allocate_slab+0x32e/0x4b0 mm/slub.c:1831
new_slab mm/slub.c:1894 [inline]
new_slab_objects mm/slub.c:2640 [inline]
___slab_alloc+0x473/0x7b0 mm/slub.c:2803
__slab_alloc.constprop.0+0xa7/0xf0 mm/slub.c:2843
slab_alloc_node mm/slub.c:2925 [inline]
__kmalloc_node_track_caller+0x2e3/0x360 mm/slub.c:4653
kmalloc_reserve net/core/skbuff.c:355 [inline]
__alloc_skb+0xde/0x340 net/core/skbuff.c:426
alloc_skb include/linux/skbuff.h:1116 [inline]
alloc_skb_with_frags+0x93/0x620 net/core/skbuff.c:6073
sock_alloc_send_pskb+0x783/0x910 net/core/sock.c:2475
mld_newpack+0x1df/0x770 net/ipv6/mcast.c:1756
add_grhead+0x265/0x330 net/ipv6/mcast.c:1859
add_grec+0x1053/0x14e0 net/ipv6/mcast.c:1997
mld_send_initial_cr.part.0+0xf6/0x230 net/ipv6/mcast.c:2244
mld_send_initial_cr net/ipv6/mcast.c:1232 [inline]
ipv6_mc_dad_complete+0x1d0/0x690 net/ipv6/mcast.c:2255
addrconf_dad_completed+0xa20/0xd60 net/ipv6/addrconf.c:4181
page last free stack trace:
reset_page_owner include/linux/page_owner.h:24 [inline]
free_pages_prepare mm/page_alloc.c:1346 [inline]
free_pcp_prepare+0x2c5/0x780 mm/page_alloc.c:1397
free_unref_page_prepare mm/page_alloc.c:3332 [inline]
free_unref_page+0x19/0x690 mm/page_alloc.c:3411
unfreeze_partials+0x16c/0x1b0 mm/slub.c:2421
put_cpu_partial+0x13d/0x230 mm/slub.c:2457
qlink_free mm/kasan/quarantine.c:146 [inline]
qlist_free_all+0x5a/0xc0 mm/kasan/quarantine.c:165
kasan_quarantine_reduce+0x180/0x200 mm/kasan/quarantine.c:272
__kasan_slab_alloc+0x8e/0xa0 mm/kasan/common.c:444
kasan_slab_alloc include/linux/kasan.h:254 [inline]
slab_post_alloc_hook mm/slab.h:519 [inline]
slab_alloc_node mm/slub.c:2959 [inline]
slab_alloc mm/slub.c:2967 [inline]
kmem_cache_alloc+0x285/0x4a0 mm/slub.c:2972
getname_flags.part.0+0x50/0x4f0 fs/namei.c:138
getname_flags fs/namei.c:2747 [inline]
user_path_at_empty+0xa1/0x100 fs/namei.c:2747
user_path_at include/linux/namei.h:57 [inline]
vfs_statx+0x142/0x390 fs/stat.c:203
vfs_fstatat fs/stat.c:225 [inline]
vfs_lstat include/linux/fs.h:3386 [inline]
__do_sys_newlstat+0x91/0x110 fs/stat.c:380
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae

Memory state around the buggy address:
ffff888034b45f80: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
ffff888034b46000: fa fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
ffff888034b46080: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
^
ffff888034b46100: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
ffff888034b46180: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
==================================================================

Ensure work is canceled before sk_free by using the sync version, and if
this is a cure then the duplicate cancel in sco_conn_del() can be cleaned
up in a seperate one.

Only for thoughts now.

+++ x/net/bluetooth/sco.c
@@ -116,7 +116,7 @@ static void sco_sock_clear_timer(struct
return;
BT_DBG("sock %p state %d", sk, sk->sk_state);
- cancel_delayed_work(&sco_pi(sk)->conn->timeout_work);
+ cancel_delayed_work_sync(&sco_pi(sk)->conn->timeout_work);
}
/* ---- SCO connections ---- */


Hi Hillf,

Thanks for looking into this.

The problem with using cancel_delayed_work_sync is that sco_sock_clear_timer is called under the locked socket. So this deadlocks with sco_sock_timeout.

What surprises me is that sock_hold is still being called on a killed socket. This part of sco_sock_timeout
sco_conn_lock(conn);
sk = conn->sk;
if (sk)
sock_hold(sk);
sco_conn_unlock(conn);

is meant to avoid races with sco_chan_del, which is called on both the shutdown and release paths, and prevent the socket from being freed while sco_sock_timeout is running. But I'm probably missing something, so thoughts would be appreciated.