[syzbot] [io-uring?] KCSAN: data-race in io_recv / io_wq_free_work

[syzbot] [io-uring?] KCSAN: data-race in io_recv / io_wq_free_work

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit:    150b567e0d57 Merge tag 'net-6.13-rc3' of git://git.kernel...
git tree:       upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=1013cd44580000
kernel config:  https://syzkaller.appspot.com/x/.config?x=1fe4854f351e948c
dashboard link: https://syzkaller.appspot.com/bug?extid=a697a4754324488bacd7
compiler:       Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40

Unfortunately, I don't have any reproducer for this issue yet.

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/05e47d657c7d/disk-150b567e.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/568329a94d6e/vmlinux-150b567e.xz
kernel image: https://storage.googleapis.com/syzbot-assets/eab7b6a3d180/bzImage-150b567e.xz

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

==================================================================
BUG: KCSAN: data-race in io_recv / io_wq_free_work

write to 0xffff88814248b848 of 8 bytes by task 22395 on cpu 1:
 io_recv+0x661/0xa70
 io_issue_sqe+0x150/0xc10 io_uring/io_uring.c:1736
 io_poll_issue+0x1a/0x20 io_uring/io_uring.c:1767
 io_poll_check_events io_uring/poll.c:289 [inline]
 io_poll_task_func+0x205/0x7c0 io_uring/poll.c:316
 io_handle_tw_list+0xe3/0x200 io_uring/io_uring.c:1053
 tctx_task_work_run+0x6e/0x1c0 io_uring/io_uring.c:1117
 tctx_task_work+0x40/0x80 io_uring/io_uring.c:1135
 task_work_run+0x13a/0x1a0 kernel/task_work.c:239
 io_run_task_work+0x1b1/0x200 io_uring/io_uring.h:343
 io_cqring_wait io_uring/io_uring.c:2594 [inline]
 __do_sys_io_uring_enter io_uring/io_uring.c:3434 [inline]
 __se_sys_io_uring_enter+0x14f5/0x1ba0 io_uring/io_uring.c:3325
 __x64_sys_io_uring_enter+0x78/0x90 io_uring/io_uring.c:3325
 x64_sys_call+0xb5e/0x2dc0 arch/x86/include/generated/asm/syscalls_64.h:427
 do_syscall_x64 arch/x86/entry/common.c:52 [inline]
 do_syscall_64+0xc9/0x1c0 arch/x86/entry/common.c:83
 entry_SYSCALL_64_after_hwframe+0x77/0x7f

read to 0xffff88814248b848 of 8 bytes by task 22396 on cpu 0:
 req_ref_put_and_test io_uring/refs.h:22 [inline]
 io_wq_free_work+0x24/0x1b0 io_uring/io_uring.c:1776
 io_worker_handle_work+0x4cb/0x9d0 io_uring/io-wq.c:604
 io_wq_worker+0x286/0x820 io_uring/io-wq.c:655
 ret_from_fork+0x4b/0x60 arch/x86/kernel/process.c:147
 ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244

value changed: 0x0000000085584038 -> 0x0000000085184138

Reported by Kernel Concurrency Sanitizer on:
CPU: 0 UID: 0 PID: 22396 Comm: iou-wrk-22395 Not tainted 6.13.0-rc2-syzkaller-00130-g150b567e0d57 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/13/2024
==================================================================


---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzkaller@googlegroups.com.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

If the report is already addressed, let syzbot know by replying with:
#syz fix: exact-commit-title

If you want to overwrite report's subsystems, reply with:
#syz set subsystems: new-subsystem
(See the list of subsystem names on the web dashboard)

If the report is a duplicate of another one, reply with:
#syz dup: exact-subject-of-another-report

If you want to undo deduplication, reply with:
#syz undup

Re: [syzbot] [io-uring?] KCSAN: data-race in io_recv / io_wq_free_work

[Pavel Begunkov]

On 12/13/24 11:11, syzbot wrote:
> ==================================================================
> BUG: KCSAN: data-race in io_recv / io_wq_free_work
> 
> write to 0xffff88814248b848 of 8 bytes by task 22395 on cpu 1:
>   io_recv+0x661/0xa70
>   io_issue_sqe+0x150/0xc10 io_uring/io_uring.c:1736
>   io_poll_issue+0x1a/0x20 io_uring/io_uring.c:1767
>   io_poll_check_events io_uring/poll.c:289 [inline]
>   io_poll_task_func+0x205/0x7c0 io_uring/poll.c:316
>   io_handle_tw_list+0xe3/0x200 io_uring/io_uring.c:1053
>   tctx_task_work_run+0x6e/0x1c0 io_uring/io_uring.c:1117
>   tctx_task_work+0x40/0x80 io_uring/io_uring.c:1135
>   task_work_run+0x13a/0x1a0 kernel/task_work.c:239
>   io_run_task_work+0x1b1/0x200 io_uring/io_uring.h:343
>   io_cqring_wait io_uring/io_uring.c:2594 [inline]
>   __do_sys_io_uring_enter io_uring/io_uring.c:3434 [inline]
>   __se_sys_io_uring_enter+0x14f5/0x1ba0 io_uring/io_uring.c:3325
>   __x64_sys_io_uring_enter+0x78/0x90 io_uring/io_uring.c:3325
>   x64_sys_call+0xb5e/0x2dc0 arch/x86/include/generated/asm/syscalls_64.h:427
>   do_syscall_x64 arch/x86/entry/common.c:52 [inline]
>   do_syscall_64+0xc9/0x1c0 arch/x86/entry/common.c:83
>   entry_SYSCALL_64_after_hwframe+0x77/0x7f
> 
> read to 0xffff88814248b848 of 8 bytes by task 22396 on cpu 0:
>   req_ref_put_and_test io_uring/refs.h:22 [inline]
>   io_wq_free_work+0x24/0x1b0 io_uring/io_uring.c:1776
>   io_worker_handle_work+0x4cb/0x9d0 io_uring/io-wq.c:604
>   io_wq_worker+0x286/0x820 io_uring/io-wq.c:655
>   ret_from_fork+0x4b/0x60 arch/x86/kernel/process.c:147
>   ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
> 
> value changed: 0x0000000085584038 -> 0x0000000085184

IIUC what that it, it's known and mild. Writes to flags are
synchronised, for concurrent reads we make sure the interesting
bits are set in advance. i.e. only a problem if compiler decides
to mask a bit while modifying an unrelated bit or so. We probably
need WRITE_ONCE or splitting flags into two sets.

-- 
Pavel Begunkov