WARNING in io_uring_setup

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit: 8ee15f32 Merge tag 'dma-mapping-5.1-1' of git://git.infrad..
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=146b7cd3200000
kernel config: https://syzkaller.appspot.com/x/.config?x=4fb64439e07a1ec0
dashboard link: https://syzkaller.appspot.com/bug?extid=cd714a07c6de2bc34293
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=15d8b397200000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=10b62ab7200000

The bug was bisected to:

commit 6c271ce2f1d572f7fa225700a13cfe7ced492434
Author: Jens Axboe <ax...@kernel.dk>
Date: Thu Jan 10 18:22:30 2019 +0000

io_uring: add submission polling

bisection log: https://syzkaller.appspot.com/x/bisect.txt?x=170a286b200000
final crash: https://syzkaller.appspot.com/x/report.txt?x=148a286b200000
console output: https://syzkaller.appspot.com/x/log.txt?x=108a286b200000

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+cd714a...@syzkaller.appspotmail.com
Fixes: 6c271ce2f1d5 ("io_uring: add submission polling")

WARNING: CPU: 1 PID: 7600 at include/linux/cpumask.h:121 cpu_max_bits_warn
include/linux/cpumask.h:121 [inline]
WARNING: CPU: 1 PID: 7600 at include/linux/cpumask.h:121 cpumask_check
include/linux/cpumask.h:128 [inline]
WARNING: CPU: 1 PID: 7600 at include/linux/cpumask.h:121 cpumask_test_cpu
include/linux/cpumask.h:344 [inline]
WARNING: CPU: 1 PID: 7600 at include/linux/cpumask.h:121
io_sq_offload_start fs/io_uring.c:2244 [inline]
WARNING: CPU: 1 PID: 7600 at include/linux/cpumask.h:121 io_uring_create
fs/io_uring.c:2851 [inline]
WARNING: CPU: 1 PID: 7600 at include/linux/cpumask.h:121
io_uring_setup+0x13b2/0x1990 fs/io_uring.c:2903
Kernel panic - not syncing: panic_on_warn set ...
CPU: 1 PID: 7600 Comm: syz-executor594 Not tainted 5.1.0-rc4+ #65
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+0x172/0x1f0 lib/dump_stack.c:113
panic+0x2cb/0x65c kernel/panic.c:214
__warn.cold+0x20/0x45 kernel/panic.c:571
report_bug+0x263/0x2b0 lib/bug.c:186
fixup_bug arch/x86/kernel/traps.c:179 [inline]
fixup_bug arch/x86/kernel/traps.c:174 [inline]
do_error_trap+0x11b/0x200 arch/x86/kernel/traps.c:272
do_invalid_op+0x37/0x50 arch/x86/kernel/traps.c:291
invalid_op+0x14/0x20 arch/x86/entry/entry_64.S:973
RIP: 0010:cpu_max_bits_warn include/linux/cpumask.h:121 [inline]
RIP: 0010:cpumask_check include/linux/cpumask.h:128 [inline]
RIP: 0010:cpumask_test_cpu include/linux/cpumask.h:344 [inline]
RIP: 0010:io_sq_offload_start fs/io_uring.c:2244 [inline]
RIP: 0010:io_uring_create fs/io_uring.c:2851 [inline]
RIP: 0010:io_uring_setup+0x13b2/0x1990 fs/io_uring.c:2903
Code: 00 00 00 00 fc ff df 48 89 da 48 c1 ea 03 80 3c 02 00 0f 84 18 fe ff
ff 48 89 df e8 e8 80 e0 ff e9 0b fe ff ff e8 2e 79 a8 ff <0f> 0b e9 db f8
ff ff e8 22 79 a8 ff 49 8d 9c 24 88 00 00 00 48 b8
RSP: 0018:ffff8880a8eb7dc0 EFLAGS: 00010293
RAX: ffff88808cdd8700 RBX: 0000000000000400 RCX: ffffffff81c80eab
RDX: 0000000000000000 RSI: ffffffff81c815d2 RDI: 0000000000000005
RBP: ffff8880a8eb7ef0 R08: ffff88808cdd8700 R09: ffffed1011c75244
R10: ffffed1011c75243 R11: ffff88808e3a921f R12: ffff88808d34a480
R13: ffff8880a8eb7ec8 R14: ffff88808d34a4c0 R15: ffff88808d34a4d4
__do_sys_io_uring_setup fs/io_uring.c:2916 [inline]
__se_sys_io_uring_setup fs/io_uring.c:2913 [inline]
__x64_sys_io_uring_setup+0x54/0x80 fs/io_uring.c:2913
do_syscall_64+0x103/0x610 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x440239
Code: 18 89 d0 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 00 48 89 f8 48 89 f7
48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff
ff 0f 83 fb 13 fc ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007fff32156718 EFLAGS: 00000246 ORIG_RAX: 00000000000001a9
RAX: ffffffffffffffda RBX: 00000000004002c8 RCX: 0000000000440239
RDX: 0000000000400b60 RSI: 0000000020000200 RDI: 0000000000000c9f
RBP: 00000000006ca018 R08: 0000000000000000 R09: 0000000000000000
R10: 00000000ffffffff R11: 0000000000000246 R12: 0000000000401ac0
R13: 0000000000401b50 R14: 0000000000000000 R15: 0000000000000000
Kernel Offset: disabled
Rebooting in 86400 seconds..


---
This bug 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 syzk...@googlegroups.com.

syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
For information about bisection process see: https://goo.gl/tpsmEJ#bisection
syzbot can test patches for this bug, for details see:
https://goo.gl/tpsmEJ#testing-patches

[Jens Axboe]

Thanks for the report, below should fix it.

--
Jens Axboe

[Jens Axboe]

Forgot to include the patch, apparently. Here it is:


diff --git a/fs/io_uring.c b/fs/io_uring.c
index 07d6ef195d05..c9bd17d6571c 100644
--- a/fs/io_uring.c
+++ b/fs/io_uring.c
@@ -2236,19 +2241,19 @@ static int io_sq_offload_start(struct io_ring_ctx *ctx,
mmgrab(current->mm);
ctx->sqo_mm = current->mm;

- ctx->sq_thread_idle = msecs_to_jiffies(p->sq_thread_idle);
- if (!ctx->sq_thread_idle)
- ctx->sq_thread_idle = HZ;
-
- ret = -EINVAL;
- if (!cpu_possible(p->sq_thread_cpu))
- goto err;
-
if (ctx->flags & IORING_SETUP_SQPOLL) {
+ ctx->sq_thread_idle = msecs_to_jiffies(p->sq_thread_idle);
+ if (!ctx->sq_thread_idle)
+ ctx->sq_thread_idle = HZ;
+
if (p->flags & IORING_SETUP_SQ_AFF) {
int cpu;

cpu = array_index_nospec(p->sq_thread_cpu, NR_CPUS);
+ ret = -EINVAL;
+ if (!cpu_possible(p->sq_thread_cpu))
+ goto err;
+
ctx->sqo_thread = kthread_create_on_cpu(io_sq_thread,
ctx, cpu,
"io_uring-sq");


--
Jens Axboe

[Mark Rutland]

Hi Jens,

On Sun, Apr 14, 2019 at 09:45:00AM -0600, Jens Axboe wrote:
> On 4/13/19 9:25 AM, Jens Axboe wrote:
> > On 4/13/19 2:26 AM, syzbot wrote:
> >> WARNING: CPU: 1 PID: 7600 at include/linux/cpumask.h:121 cpu_max_bits_warn
> >> include/linux/cpumask.h:121 [inline]
> >> WARNING: CPU: 1 PID: 7600 at include/linux/cpumask.h:121 cpumask_check
> >> include/linux/cpumask.h:128 [inline]
> >> WARNING: CPU: 1 PID: 7600 at include/linux/cpumask.h:121 cpumask_test_cpu
> >> include/linux/cpumask.h:344 [inline]
> >> WARNING: CPU: 1 PID: 7600 at include/linux/cpumask.h:121
> >> io_sq_offload_start fs/io_uring.c:2244 [inline]
> >> WARNING: CPU: 1 PID: 7600 at include/linux/cpumask.h:121 io_uring_create
> >> fs/io_uring.c:2851 [inline]
> >> WARNING: CPU: 1 PID: 7600 at include/linux/cpumask.h:121
> >> io_uring_setup+0x13b2/0x1990 fs/io_uring.c:2903

As a heads-up, I'm seeing this on arm64 in v5.1-rc7; example splat below. I
believe that commit:

917257daa0fea7a0 ("io_uring: only test SQPOLL cpu after we've verified it")

... was intended to fix this?

IIUC, the problem is that cpu_possible(cpu) can't accept a cpu index above
nr_cpu_ids, since it is defined as:

cpumask_test_cpu((cpu), cpu_possible_mask)

... and so we should first check whether cpu >= nr_cpu_ids.

Arguably that could/should live directly in cpu_possible(), but I see that's
open-coded in a few places:

[mark@lakrids:~/src/linux]% git grep -w cpu_possible | grep nr_cpu_ids
arch/x86/mm/numa.c: if (cpu >= nr_cpu_ids || !cpu_possible(cpu)) {
arch/x86/xen/smp_pv.c: for (cpu = nr_cpu_ids - 1; !cpu_possible(cpu); cpu--)
drivers/base/cpu.c: if (cpu < nr_cpu_ids && cpu_possible(cpu))
drivers/scsi/libfc/fc_exch.c: if (cpu >= nr_cpu_ids || !cpu_possible(cpu)) {
drivers/xen/cpu_hotplug.c: if (cpu >= nr_cpu_ids || !cpu_possible(cpu))

Thanks,
Mark.

WARNING: CPU: 1 PID: 27601 at include/linux/cpumask.h:121 cpu_max_bits_warn include/linux/cpumask.h:121 [inline]
WARNING: CPU: 1 PID: 27601 at include/linux/cpumask.h:121 cpumask_check include/linux/cpumask.h:128 [inline]
WARNING: CPU: 1 PID: 27601 at include/linux/cpumask.h:121 cpumask_test_cpu include/linux/cpumask.h:344 [inline]
WARNING: CPU: 1 PID: 27601 at include/linux/cpumask.h:121 io_sq_offload_start fs/io_uring.c:2244 [inline]
WARNING: CPU: 1 PID: 27601 at include/linux/cpumask.h:121 io_uring_create fs/io_uring.c:2864 [inline]
WARNING: CPU: 1 PID: 27601 at include/linux/cpumask.h:121 io_uring_setup+0x1108/0x15a0 fs/io_uring.c:2916

Kernel panic - not syncing: panic_on_warn set ...

CPU: 1 PID: 27601 Comm: syz-executor.0 Not tainted 5.1.0-rc7 #3
Hardware name: linux,dummy-virt (DT)
Call trace:
dump_backtrace+0x0/0x2f0 include/linux/compiler.h:193
show_stack+0x20/0x30 arch/arm64/kernel/traps.c:158
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x110/0x190 lib/dump_stack.c:113
panic+0x384/0x68c kernel/panic.c:214
__warn+0x2bc/0x2c0 kernel/panic.c:571
report_bug+0x228/0x2d8 lib/bug.c:186
bug_handler+0xa0/0x1a0 arch/arm64/kernel/traps.c:956
call_break_hook arch/arm64/kernel/debug-monitors.c:301 [inline]
brk_handler+0x1d4/0x388 arch/arm64/kernel/debug-monitors.c:316
do_debug_exception+0x1a0/0x468 arch/arm64/mm/fault.c:831
el1_dbg+0x18/0x8c
cpu_max_bits_warn include/linux/cpumask.h:121 [inline]
cpumask_check include/linux/cpumask.h:128 [inline]
cpumask_test_cpu include/linux/cpumask.h:344 [inline]
io_sq_offload_start fs/io_uring.c:2244 [inline]
io_uring_create fs/io_uring.c:2864 [inline]
io_uring_setup+0x1108/0x15a0 fs/io_uring.c:2916
__do_sys_io_uring_setup fs/io_uring.c:2929 [inline]
__se_sys_io_uring_setup fs/io_uring.c:2926 [inline]
__arm64_sys_io_uring_setup+0x50/0x70 fs/io_uring.c:2926
__invoke_syscall arch/arm64/kernel/syscall.c:35 [inline]
invoke_syscall arch/arm64/kernel/syscall.c:47 [inline]
el0_svc_common.constprop.0+0x148/0x2e0 arch/arm64/kernel/syscall.c:83
el0_svc_handler+0xdc/0x100 arch/arm64/kernel/syscall.c:129
el0_svc+0x8/0xc arch/arm64/kernel/entry.S:948
SMP: stopping secondary CPUs
Dumping ftrace buffer:
(ftrace buffer empty)
Kernel Offset: disabled
CPU features: 0x002,23000438
Memory Limit: none
Rebooting in 1 seconds..