Re: [syzbot] KASAN: wild-memory-access Read in io_wq_worker_running

Re: [syzbot] KASAN: wild-memory-access Read in io_wq_worker_running

[syzbot]

syzbot has found a reproducer for the following issue on:

HEAD commit:    a689b938df39 Merge tag 'block-2023-01-06' of git://git.ker..
git tree:       upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=1278ab3a480000
kernel config:  https://syzkaller.appspot.com/x/.config?x=ff5cf657dd0e7643
dashboard link: https://syzkaller.appspot.com/bug?extid=d56ec896af3637bdb7e4
compiler:       gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=137f9b3a480000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=17d080ba480000

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/e2cef31af3d4/disk-a689b938.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/107ea77bb030/vmlinux-a689b938.xz
kernel image: https://storage.googleapis.com/syzbot-assets/102597c4f641/bzImage-a689b938.xz

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+d56ec896af3637bdb7e4@syzkaller.appspotmail.com

==================================================================
BUG: KASAN: use-after-free in io_wq_worker_running+0x114/0x130 io_uring/io-wq.c:674
Read of size 4 at addr ffff888020e9f404 by task iou-wrk-6429/6430

CPU: 1 PID: 6430 Comm: iou-wrk-6429 Not tainted 6.2.0-rc2-syzkaller-00256-ga689b938df39 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0xd1/0x138 lib/dump_stack.c:106
 print_address_description mm/kasan/report.c:306 [inline]
 print_report+0x15e/0x45d mm/kasan/report.c:417
 kasan_report+0xbf/0x1f0 mm/kasan/report.c:517
 io_wq_worker_running+0x114/0x130 io_uring/io-wq.c:674
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6690
 __mutex_lock_common kernel/locking/mutex.c:679 [inline]
 __mutex_lock+0xa48/0x1360 kernel/locking/mutex.c:747
 io_ring_submit_lock io_uring/io_uring.h:215 [inline]
 io_poll_cancel+0x1ae/0x1e0 io_uring/poll.c:846
 io_try_cancel+0x176/0x230 io_uring/cancel.c:97
 __io_async_cancel+0xa0/0x3f0 io_uring/cancel.c:140
 io_async_cancel+0x27a/0x480 io_uring/cancel.c:193
 io_issue_sqe+0x156/0x1220 io_uring/io_uring.c:1856
 io_wq_submit_work+0x29c/0xdc0 io_uring/io_uring.c:1932
 io_worker_handle_work+0xc41/0x1c60 io_uring/io-wq.c:587
 io_wqe_worker+0xa5b/0xe40 io_uring/io-wq.c:632
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:308
 </TASK>

Allocated by task 6429:
 kasan_save_stack+0x22/0x40 mm/kasan/common.c:45
 kasan_set_track+0x25/0x30 mm/kasan/common.c:52
 ____kasan_kmalloc mm/kasan/common.c:371 [inline]
 ____kasan_kmalloc mm/kasan/common.c:330 [inline]
 __kasan_kmalloc+0xa5/0xb0 mm/kasan/common.c:380
 kmalloc_node include/linux/slab.h:606 [inline]
 kzalloc_node include/linux/slab.h:731 [inline]
 create_io_worker+0x10c/0x630 io_uring/io-wq.c:801
 io_wqe_create_worker io_uring/io-wq.c:310 [inline]
 io_wqe_enqueue+0x6c3/0xbc0 io_uring/io-wq.c:936
 io_queue_iowq+0x282/0x5c0 io_uring/io_uring.c:475
 io_queue_sqe_fallback+0xf3/0x190 io_uring/io_uring.c:2059
 io_submit_sqe io_uring/io_uring.c:2281 [inline]
 io_submit_sqes+0x11db/0x1e60 io_uring/io_uring.c:2397
 __do_sys_io_uring_enter+0xc1d/0x2540 io_uring/io_uring.c:3345
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x39/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x63/0xcd

Freed by task 6430:
 kasan_save_stack+0x22/0x40 mm/kasan/common.c:45
 kasan_set_track+0x25/0x30 mm/kasan/common.c:52
 kasan_save_free_info+0x2e/0x40 mm/kasan/generic.c:518
 ____kasan_slab_free mm/kasan/common.c:236 [inline]
 ____kasan_slab_free+0x160/0x1c0 mm/kasan/common.c:200
 kasan_slab_free include/linux/kasan.h:177 [inline]
 slab_free_hook mm/slub.c:1781 [inline]
 slab_free_freelist_hook+0x8b/0x1c0 mm/slub.c:1807
 slab_free mm/slub.c:3787 [inline]
 __kmem_cache_free+0xaf/0x3b0 mm/slub.c:3800
 io_wq_cancel_tw_create io_uring/io-wq.c:1233 [inline]
 io_queue_worker_create+0x567/0x660 io_uring/io-wq.c:381
 io_wqe_dec_running+0x1e4/0x240 io_uring/io-wq.c:410
 io_wq_worker_sleeping+0xa6/0xc0 io_uring/io-wq.c:698
 sched_submit_work kernel/sched/core.c:6597 [inline]
 schedule+0x16e/0x1b0 kernel/sched/core.c:6628
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6690
 __mutex_lock_common kernel/locking/mutex.c:679 [inline]
 __mutex_lock+0xa48/0x1360 kernel/locking/mutex.c:747
 io_ring_submit_lock io_uring/io_uring.h:215 [inline]
 io_poll_cancel+0x1ae/0x1e0 io_uring/poll.c:846
 io_try_cancel+0x176/0x230 io_uring/cancel.c:97
 __io_async_cancel+0xa0/0x3f0 io_uring/cancel.c:140
 io_async_cancel+0x27a/0x480 io_uring/cancel.c:193
 io_issue_sqe+0x156/0x1220 io_uring/io_uring.c:1856
 io_wq_submit_work+0x29c/0xdc0 io_uring/io_uring.c:1932
 io_worker_handle_work+0xc41/0x1c60 io_uring/io-wq.c:587
 io_wqe_worker+0xa5b/0xe40 io_uring/io-wq.c:632
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:308

Last potentially related work creation:
 kasan_save_stack+0x22/0x40 mm/kasan/common.c:45
 __kasan_record_aux_stack+0xbc/0xd0 mm/kasan/generic.c:488
 task_work_add+0x7f/0x2c0 kernel/task_work.c:48
 io_queue_worker_create+0x41d/0x660 io_uring/io-wq.c:373
 io_wqe_dec_running+0x1e4/0x240 io_uring/io-wq.c:410
 io_wq_worker_sleeping+0xa6/0xc0 io_uring/io-wq.c:698
 sched_submit_work kernel/sched/core.c:6597 [inline]
 schedule+0x16e/0x1b0 kernel/sched/core.c:6628
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6690
 __mutex_lock_common kernel/locking/mutex.c:679 [inline]
 __mutex_lock+0xa48/0x1360 kernel/locking/mutex.c:747
 io_ring_submit_lock io_uring/io_uring.h:215 [inline]
 io_poll_cancel+0x1ae/0x1e0 io_uring/poll.c:846
 io_try_cancel+0x176/0x230 io_uring/cancel.c:97
 __io_async_cancel+0xa0/0x3f0 io_uring/cancel.c:140
 io_async_cancel+0x27a/0x480 io_uring/cancel.c:193
 io_issue_sqe+0x156/0x1220 io_uring/io_uring.c:1856
 io_wq_submit_work+0x29c/0xdc0 io_uring/io_uring.c:1932
 io_worker_handle_work+0xc41/0x1c60 io_uring/io-wq.c:587
 io_wqe_worker+0xa5b/0xe40 io_uring/io-wq.c:632
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:308

The buggy address belongs to the object at ffff888020e9f400
 which belongs to the cache kmalloc-512 of size 512
The buggy address is located 4 bytes inside of
 512-byte region [ffff888020e9f400, ffff888020e9f600)

The buggy address belongs to the physical page:
page:ffffea000083a700 refcount:1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x20e9c
head:ffffea000083a700 order:2 compound_mapcount:0 subpages_mapcount:0 compound_pincount:0
ksm flags: 0xfff00000010200(slab|head|node=0|zone=1|lastcpupid=0x7ff)
raw: 00fff00000010200 ffff888012441c80 ffffea000078b400 dead000000000003
raw: 0000000000000000 0000000000100010 00000001ffffffff 0000000000000000
page dumped because: kasan: bad access detected
page_owner tracks the page as allocated
page last allocated via order 2, migratetype Unmovable, gfp_mask 0xd2000(__GFP_NOWARN|__GFP_NORETRY|__GFP_COMP|__GFP_NOMEMALLOC), pid 1, tgid 1 (swapper/0), ts 9022994950, free_ts 0
 prep_new_page mm/page_alloc.c:2531 [inline]
 get_page_from_freelist+0x119c/0x2ce0 mm/page_alloc.c:4283
 __alloc_pages+0x1cb/0x5b0 mm/page_alloc.c:5549
 alloc_page_interleave+0x1e/0x200 mm/mempolicy.c:2119
 alloc_pages+0x233/0x270 mm/mempolicy.c:2281
 alloc_slab_page mm/slub.c:1851 [inline]
 allocate_slab+0x25f/0x350 mm/slub.c:1998
 new_slab mm/slub.c:2051 [inline]
 ___slab_alloc+0xa91/0x1400 mm/slub.c:3193
 __slab_alloc.constprop.0+0x56/0xa0 mm/slub.c:3292
 __slab_alloc_node mm/slub.c:3345 [inline]
 slab_alloc_node mm/slub.c:3442 [inline]
 __kmem_cache_alloc_node+0x1a4/0x430 mm/slub.c:3491
 kmalloc_trace+0x26/0x60 mm/slab_common.c:1062
 kmalloc include/linux/slab.h:580 [inline]
 usb_cache_string+0x62/0x150 drivers/usb/core/message.c:1027
 usb_enumerate_device drivers/usb/core/hub.c:2415 [inline]
 usb_new_device+0x167/0x7b0 drivers/usb/core/hub.c:2543
 register_root_hub+0x421/0x573 drivers/usb/core/hcd.c:1017
 usb_add_hcd.cold+0x100c/0x13a1 drivers/usb/core/hcd.c:2991
 dummy_hcd_probe+0x1a3/0x314 drivers/usb/gadget/udc/dummy_hcd.c:2676
 platform_probe+0x100/0x1f0 drivers/base/platform.c:1400
 call_driver_probe drivers/base/dd.c:560 [inline]
 really_probe+0x249/0xb90 drivers/base/dd.c:639
page_owner free stack trace missing

Memory state around the buggy address:
 ffff888020e9f300: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
 ffff888020e9f380: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
>ffff888020e9f400: fa fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
                   ^
 ffff888020e9f480: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
 ffff888020e9f500: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
==================================================================

Re: [syzbot] KASAN: wild-memory-access Read in io_wq_worker_running

[Jens Axboe]

#syz test: git://git.kernel.dk/linux.git io_uring-6.2

-- 
Jens Axboe

Re: [syzbot] KASAN: wild-memory-access Read in io_wq_worker_running

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:
INFO: rcu detected stall in corrupted

rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: { P5774 } 2664 jiffies s: 2777 root: 0x0/T
rcu: blocking rcu_node structures (internal RCU debug):


Tested on:

commit:         e6db6f93 io_uring/io-wq: only free worker if it was al..
git tree:       git://git.kernel.dk/linux.git io_uring-6.2
console output: https://syzkaller.appspot.com/x/log.txt?x=116df816480000
kernel config:  https://syzkaller.appspot.com/x/.config?x=2edd87fe5cbdf43f
dashboard link: https://syzkaller.appspot.com/bug?extid=d56ec896af3637bdb7e4
compiler:       gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2

Note: no patches were applied.

Re: [syzbot] KASAN: wild-memory-access Read in io_wq_worker_running

[Jens Axboe]

On 1/8/23 7:34 PM, syzbot wrote:
> Hello,
> 
> syzbot has tested the proposed patch but the reproducer is still triggering an issue:
> INFO: rcu detected stall in corrupted
> 
> rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: { P5774 } 2664 jiffies s: 2777 root: 0x0/T
> rcu: blocking rcu_node structures (internal RCU debug):

Don't think that's related, probably because of the earlier base of
that branch. Let's try something that's merged to current master:

#syz test: git://git.kernel.dk/linux.git syztest

-- 
Jens Axboe

Re: [syzbot] KASAN: wild-memory-access Read in io_wq_worker_running

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:
INFO: rcu detected stall in corrupted

rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: { P5561 } 2648 jiffies s: 2797 root: 0x0/T
rcu: blocking rcu_node structures (internal RCU debug):


Tested on:

commit:         a4b98579 Merge branch 'io_uring-6.2' into syztest
git tree:       git://git.kernel.dk/linux.git syztest
console output: https://syzkaller.appspot.com/x/log.txt?x=17668ed6480000
kernel config:  https://syzkaller.appspot.com/x/.config?x=8b79b14037065d92
dashboard link: https://syzkaller.appspot.com/bug?extid=d56ec896af3637bdb7e4
compiler:       gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2

Note: no patches were applied.