2023-04-21 14:35:34

by syzbot

[permalink] [raw]
Subject: [syzbot] [ext4?] [mm?] KCSAN: data-race in strscpy / strscpy (3)

Hello,

syzbot found the following issue on:

HEAD commit: 76f598ba7d8e Merge tag 'for-linus' of git://git.kernel.org..
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=133bfbedc80000
kernel config: https://syzkaller.appspot.com/x/.config?x=9c5d44636e91081b
dashboard link: https://syzkaller.appspot.com/bug?extid=c2de99a72baaa06d31f3
compiler: Debian clang version 15.0.7, GNU ld (GNU Binutils for Debian) 2.35.2

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

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/a3654f5f77b9/disk-76f598ba.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/abfb4aaa5772/vmlinux-76f598ba.xz
kernel image: https://storage.googleapis.com/syzbot-assets/789fb5546551/bzImage-76f598ba.xz

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: [email protected]

==================================================================
BUG: KCSAN: data-race in strscpy / strscpy

write to 0xffff88812ed8b730 of 8 bytes by task 16157 on cpu 1:
strscpy+0xa9/0x170 lib/string.c:165
strscpy_pad+0x27/0x80 lib/string_helpers.c:835
__set_task_comm+0x46/0x140 fs/exec.c:1232
set_task_comm include/linux/sched.h:1984 [inline]
__kthread_create_on_node+0x2b2/0x320 kernel/kthread.c:474
kthread_create_on_node+0x8a/0xb0 kernel/kthread.c:512
ext4_run_lazyinit_thread fs/ext4/super.c:3848 [inline]
ext4_register_li_request+0x407/0x650 fs/ext4/super.c:3983
__ext4_fill_super fs/ext4/super.c:5480 [inline]
ext4_fill_super+0x3f4a/0x43f0 fs/ext4/super.c:5637
get_tree_bdev+0x2b1/0x3a0 fs/super.c:1303
ext4_get_tree+0x1c/0x20 fs/ext4/super.c:5668
vfs_get_tree+0x51/0x190 fs/super.c:1510
do_new_mount+0x200/0x650 fs/namespace.c:3042
path_mount+0x498/0xb40 fs/namespace.c:3372
do_mount fs/namespace.c:3385 [inline]
__do_sys_mount fs/namespace.c:3594 [inline]
__se_sys_mount+0x27f/0x2d0 fs/namespace.c:3571
__x64_sys_mount+0x67/0x80 fs/namespace.c:3571
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x41/0xc0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x63/0xcd

read to 0xffff88812ed8b733 of 1 bytes by task 16161 on cpu 0:
strscpy+0xde/0x170 lib/string.c:174
____bpf_get_current_comm kernel/bpf/helpers.c:260 [inline]
bpf_get_current_comm+0x45/0x70 kernel/bpf/helpers.c:252
___bpf_prog_run+0x281/0x3050 kernel/bpf/core.c:1822
__bpf_prog_run32+0x74/0xa0 kernel/bpf/core.c:2043
bpf_dispatcher_nop_func include/linux/bpf.h:1124 [inline]
__bpf_prog_run include/linux/filter.h:601 [inline]
bpf_prog_run include/linux/filter.h:608 [inline]
__bpf_trace_run kernel/trace/bpf_trace.c:2263 [inline]
bpf_trace_run4+0x9f/0x140 kernel/trace/bpf_trace.c:2304
__traceiter_sched_switch+0x3a/0x50 include/trace/events/sched.h:222
trace_sched_switch include/trace/events/sched.h:222 [inline]
__schedule+0x7e7/0x8e0 kernel/sched/core.c:6622
schedule+0x51/0x80 kernel/sched/core.c:6701
schedule_preempt_disabled+0x10/0x20 kernel/sched/core.c:6760
kthread+0x11c/0x1e0 kernel/kthread.c:369
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:308

value changed: 0x72 -> 0x34

Reported by Kernel Concurrency Sanitizer on:
CPU: 0 PID: 16161 Comm: ext4lazyinit Not tainted 6.3.0-rc5-syzkaller-00022-g76f598ba7d8e #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 03/30/2023
==================================================================


---
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 [email protected].

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


2023-04-21 14:57:07

by Dmitry Vyukov

[permalink] [raw]
Subject: Re: [syzbot] [ext4?] [mm?] KCSAN: data-race in strscpy / strscpy (3)

On Fri, 21 Apr 2023 at 16:33, syzbot
<[email protected]> wrote:
>
> Hello,
>
> syzbot found the following issue on:
>
> HEAD commit: 76f598ba7d8e Merge tag 'for-linus' of git://git.kernel.org..
> git tree: upstream
> console output: https://syzkaller.appspot.com/x/log.txt?x=133bfbedc80000
> kernel config: https://syzkaller.appspot.com/x/.config?x=9c5d44636e91081b
> dashboard link: https://syzkaller.appspot.com/bug?extid=c2de99a72baaa06d31f3
> compiler: Debian clang version 15.0.7, GNU ld (GNU Binutils for Debian) 2.35.2
>
> Unfortunately, I don't have any reproducer for this issue yet.
>
> Downloadable assets:
> disk image: https://storage.googleapis.com/syzbot-assets/a3654f5f77b9/disk-76f598ba.raw.xz
> vmlinux: https://storage.googleapis.com/syzbot-assets/abfb4aaa5772/vmlinux-76f598ba.xz
> kernel image: https://storage.googleapis.com/syzbot-assets/789fb5546551/bzImage-76f598ba.xz
>
> IMPORTANT: if you fix the issue, please add the following tag to the commit:
> Reported-by: [email protected]

+bpf maintainers

If I am reading this correctly, this can cause a leak of kernel memory
and/or crash via bpf_get_current_comm helper.

strcpy() can temporary leave comm buffer non-0 terminated as it
terminates it only after the copy:
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/lib/string.c?id=76f598ba7d8e2bfb4855b5298caedd5af0c374a8#n184

If bpf_get_current_comm() observes such non-0-terminated comm, it will
start reading off bounds.

> ==================================================================
> BUG: KCSAN: data-race in strscpy / strscpy
>
> write to 0xffff88812ed8b730 of 8 bytes by task 16157 on cpu 1:
> strscpy+0xa9/0x170 lib/string.c:165
> strscpy_pad+0x27/0x80 lib/string_helpers.c:835
> __set_task_comm+0x46/0x140 fs/exec.c:1232
> set_task_comm include/linux/sched.h:1984 [inline]
> __kthread_create_on_node+0x2b2/0x320 kernel/kthread.c:474
> kthread_create_on_node+0x8a/0xb0 kernel/kthread.c:512
> ext4_run_lazyinit_thread fs/ext4/super.c:3848 [inline]
> ext4_register_li_request+0x407/0x650 fs/ext4/super.c:3983
> __ext4_fill_super fs/ext4/super.c:5480 [inline]
> ext4_fill_super+0x3f4a/0x43f0 fs/ext4/super.c:5637
> get_tree_bdev+0x2b1/0x3a0 fs/super.c:1303
> ext4_get_tree+0x1c/0x20 fs/ext4/super.c:5668
> vfs_get_tree+0x51/0x190 fs/super.c:1510
> do_new_mount+0x200/0x650 fs/namespace.c:3042
> path_mount+0x498/0xb40 fs/namespace.c:3372
> do_mount fs/namespace.c:3385 [inline]
> __do_sys_mount fs/namespace.c:3594 [inline]
> __se_sys_mount+0x27f/0x2d0 fs/namespace.c:3571
> __x64_sys_mount+0x67/0x80 fs/namespace.c:3571
> do_syscall_x64 arch/x86/entry/common.c:50 [inline]
> do_syscall_64+0x41/0xc0 arch/x86/entry/common.c:80
> entry_SYSCALL_64_after_hwframe+0x63/0xcd
>
> read to 0xffff88812ed8b733 of 1 bytes by task 16161 on cpu 0:
> strscpy+0xde/0x170 lib/string.c:174
> ____bpf_get_current_comm kernel/bpf/helpers.c:260 [inline]
> bpf_get_current_comm+0x45/0x70 kernel/bpf/helpers.c:252
> ___bpf_prog_run+0x281/0x3050 kernel/bpf/core.c:1822
> __bpf_prog_run32+0x74/0xa0 kernel/bpf/core.c:2043
> bpf_dispatcher_nop_func include/linux/bpf.h:1124 [inline]
> __bpf_prog_run include/linux/filter.h:601 [inline]
> bpf_prog_run include/linux/filter.h:608 [inline]
> __bpf_trace_run kernel/trace/bpf_trace.c:2263 [inline]
> bpf_trace_run4+0x9f/0x140 kernel/trace/bpf_trace.c:2304
> __traceiter_sched_switch+0x3a/0x50 include/trace/events/sched.h:222
> trace_sched_switch include/trace/events/sched.h:222 [inline]
> __schedule+0x7e7/0x8e0 kernel/sched/core.c:6622
> schedule+0x51/0x80 kernel/sched/core.c:6701
> schedule_preempt_disabled+0x10/0x20 kernel/sched/core.c:6760
> kthread+0x11c/0x1e0 kernel/kthread.c:369
> ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:308
>
> value changed: 0x72 -> 0x34
>
> Reported by Kernel Concurrency Sanitizer on:
> CPU: 0 PID: 16161 Comm: ext4lazyinit Not tainted 6.3.0-rc5-syzkaller-00022-g76f598ba7d8e #0
> Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 03/30/2023
> ==================================================================
>
>
> ---
> 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 [email protected].
>
> syzbot will keep track of this issue. See:
> https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

2023-04-21 18:28:07

by Theodore Ts'o

[permalink] [raw]
Subject: Re: [syzbot] [ext4?] [mm?] KCSAN: data-race in strscpy / strscpy (3)

On Fri, Apr 21, 2023 at 12:40:45PM -0500, Mike Christie wrote:
>
> I didn't see the beginning of this thread and I think the part of the
> sysbot report that lists the patches/trees being used got cut off so
> I'm not 100% sure what's in the kernel.

Syzbot reported this on commit 76f598ba7d8e which is upstream after v6.3-rc6.

Cheers,

- Ted

2023-04-24 08:08:35

by Christian Brauner

[permalink] [raw]
Subject: Re: [syzbot] [ext4?] [mm?] KCSAN: data-race in strscpy / strscpy (3)

On Fri, Apr 21, 2023 at 12:40:45PM -0500, Mike Christie wrote:
> cc'ing Christian, because I might have fixed this with a patch in
> his tree.
>
> On 4/21/23 9:58 AM, Matthew Wilcox wrote:
> > I'm not sure how it is that bpf is able to see the task before comm is
> > initialised; that seems to be the real race here, that comm is not set
> > before the kthread is a schedulable entity? Adding the scheduler people.
> >
> >>> ==================================================================
> >>> BUG: KCSAN: data-race in strscpy / strscpy
> >>>
> >>> write to 0xffff88812ed8b730 of 8 bytes by task 16157 on cpu 1:
> >>> strscpy+0xa9/0x170 lib/string.c:165
> >>> strscpy_pad+0x27/0x80 lib/string_helpers.c:835
> >>> __set_task_comm+0x46/0x140 fs/exec.c:1232
> >>> set_task_comm include/linux/sched.h:1984 [inline]
> >>> __kthread_create_on_node+0x2b2/0x320 kernel/kthread.c:474
> >>> kthread_create_on_node+0x8a/0xb0 kernel/kthread.c:512
> >>> ext4_run_lazyinit_thread fs/ext4/super.c:3848 [inline]
> >>> ext4_register_li_request+0x407/0x650 fs/ext4/super.c:3983
> >>> __ext4_fill_super fs/ext4/super.c:5480 [inline]
> >>> ext4_fill_super+0x3f4a/0x43f0 fs/ext4/super.c:5637
> >>> get_tree_bdev+0x2b1/0x3a0 fs/super.c:1303
> >>> ext4_get_tree+0x1c/0x20 fs/ext4/super.c:5668
> >>> vfs_get_tree+0x51/0x190 fs/super.c:1510
> >>> do_new_mount+0x200/0x650 fs/namespace.c:3042
> >>> path_mount+0x498/0xb40 fs/namespace.c:3372
> >>> do_mount fs/namespace.c:3385 [inline]
> >>> __do_sys_mount fs/namespace.c:3594 [inline]
> >>> __se_sys_mount+0x27f/0x2d0 fs/namespace.c:3571
> >>> __x64_sys_mount+0x67/0x80 fs/namespace.c:3571
> >>> do_syscall_x64 arch/x86/entry/common.c:50 [inline]
> >>> do_syscall_64+0x41/0xc0 arch/x86/entry/common.c:80
> >>> entry_SYSCALL_64_after_hwframe+0x63/0xcd
> >>>
> >>> read to 0xffff88812ed8b733 of 1 bytes by task 16161 on cpu 0:
> >>> strscpy+0xde/0x170 lib/string.c:174
> >>> ____bpf_get_current_comm kernel/bpf/helpers.c:260 [inline]
> >>> bpf_get_current_comm+0x45/0x70 kernel/bpf/helpers.c:252
> >>> ___bpf_prog_run+0x281/0x3050 kernel/bpf/core.c:1822
> >>> __bpf_prog_run32+0x74/0xa0 kernel/bpf/core.c:2043
> >>> bpf_dispatcher_nop_func include/linux/bpf.h:1124 [inline]
> >>> __bpf_prog_run include/linux/filter.h:601 [inline]
> >>> bpf_prog_run include/linux/filter.h:608 [inline]
> >>> __bpf_trace_run kernel/trace/bpf_trace.c:2263 [inline]
> >>> bpf_trace_run4+0x9f/0x140 kernel/trace/bpf_trace.c:2304
> >>> __traceiter_sched_switch+0x3a/0x50 include/trace/events/sched.h:222
> >>> trace_sched_switch include/trace/events/sched.h:222 [inline]
> >>> __schedule+0x7e7/0x8e0 kernel/sched/core.c:6622
> >>> schedule+0x51/0x80 kernel/sched/core.c:6701
> >>> schedule_preempt_disabled+0x10/0x20 kernel/sched/core.c:6760
> >>> kthread+0x11c/0x1e0 kernel/kthread.c:369
> >>> ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:308
> >>>
>
>
> I didn't see the beginning of this thread and I think the part of the
> sysbot report that lists the patches/trees being used got cut off so
> I'm not 100% sure what's in the kernel.
>
> In Linus's current tree we do set_task_comm in __kthread_create_on_node
> after waiting on the kthread_create_info completion which is completed by
> threadd(). At this time, kthread() has already done the complete() on the
> kthread_create_info completion and started to run the threadfn function and
> that could be running. So we can hit the race that way.
>
>
> In linux next, from
> https://git.kernel.org/pub/scm/linux/kernel/git/brauner/linux.git/log/?h=kernel.user_worker
> we have:
>
> commit cf587db2ee0261c74d04f61f39783db88a0b65e4
> Author: Mike Christie <[email protected]>
> Date: Fri Mar 10 16:03:23 2023 -0600
>
> kernel: Allow a kernel thread's name to be set in copy_process
>
> and so now copy_process() sets the name before the taskfn is started, so we
> shouldn't hit any races like above.

Yeah, that looks like it should fix it.

Afaict, this has no reproducer so there's no point in letting syzbot
test on this. I've sent the pull request for the kernel user worker
series on Friday. So I guess we'll see whether it's reproducible on
v6.4-rc1.


2023-04-24 08:35:25

by Dmitry Vyukov

[permalink] [raw]
Subject: Re: [syzbot] [ext4?] [mm?] KCSAN: data-race in strscpy / strscpy (3)

On Mon, 24 Apr 2023 at 09:59, Christian Brauner <[email protected]> wrote:
>
> On Fri, Apr 21, 2023 at 12:40:45PM -0500, Mike Christie wrote:
> > cc'ing Christian, because I might have fixed this with a patch in
> > his tree.
> >
> > On 4/21/23 9:58 AM, Matthew Wilcox wrote:
> > > I'm not sure how it is that bpf is able to see the task before comm is
> > > initialised; that seems to be the real race here, that comm is not set
> > > before the kthread is a schedulable entity? Adding the scheduler people.
> > >
> > >>> ==================================================================
> > >>> BUG: KCSAN: data-race in strscpy / strscpy
> > >>>
> > >>> write to 0xffff88812ed8b730 of 8 bytes by task 16157 on cpu 1:
> > >>> strscpy+0xa9/0x170 lib/string.c:165
> > >>> strscpy_pad+0x27/0x80 lib/string_helpers.c:835
> > >>> __set_task_comm+0x46/0x140 fs/exec.c:1232
> > >>> set_task_comm include/linux/sched.h:1984 [inline]
> > >>> __kthread_create_on_node+0x2b2/0x320 kernel/kthread.c:474
> > >>> kthread_create_on_node+0x8a/0xb0 kernel/kthread.c:512
> > >>> ext4_run_lazyinit_thread fs/ext4/super.c:3848 [inline]
> > >>> ext4_register_li_request+0x407/0x650 fs/ext4/super.c:3983
> > >>> __ext4_fill_super fs/ext4/super.c:5480 [inline]
> > >>> ext4_fill_super+0x3f4a/0x43f0 fs/ext4/super.c:5637
> > >>> get_tree_bdev+0x2b1/0x3a0 fs/super.c:1303
> > >>> ext4_get_tree+0x1c/0x20 fs/ext4/super.c:5668
> > >>> vfs_get_tree+0x51/0x190 fs/super.c:1510
> > >>> do_new_mount+0x200/0x650 fs/namespace.c:3042
> > >>> path_mount+0x498/0xb40 fs/namespace.c:3372
> > >>> do_mount fs/namespace.c:3385 [inline]
> > >>> __do_sys_mount fs/namespace.c:3594 [inline]
> > >>> __se_sys_mount+0x27f/0x2d0 fs/namespace.c:3571
> > >>> __x64_sys_mount+0x67/0x80 fs/namespace.c:3571
> > >>> do_syscall_x64 arch/x86/entry/common.c:50 [inline]
> > >>> do_syscall_64+0x41/0xc0 arch/x86/entry/common.c:80
> > >>> entry_SYSCALL_64_after_hwframe+0x63/0xcd
> > >>>
> > >>> read to 0xffff88812ed8b733 of 1 bytes by task 16161 on cpu 0:
> > >>> strscpy+0xde/0x170 lib/string.c:174
> > >>> ____bpf_get_current_comm kernel/bpf/helpers.c:260 [inline]
> > >>> bpf_get_current_comm+0x45/0x70 kernel/bpf/helpers.c:252
> > >>> ___bpf_prog_run+0x281/0x3050 kernel/bpf/core.c:1822
> > >>> __bpf_prog_run32+0x74/0xa0 kernel/bpf/core.c:2043
> > >>> bpf_dispatcher_nop_func include/linux/bpf.h:1124 [inline]
> > >>> __bpf_prog_run include/linux/filter.h:601 [inline]
> > >>> bpf_prog_run include/linux/filter.h:608 [inline]
> > >>> __bpf_trace_run kernel/trace/bpf_trace.c:2263 [inline]
> > >>> bpf_trace_run4+0x9f/0x140 kernel/trace/bpf_trace.c:2304
> > >>> __traceiter_sched_switch+0x3a/0x50 include/trace/events/sched.h:222
> > >>> trace_sched_switch include/trace/events/sched.h:222 [inline]
> > >>> __schedule+0x7e7/0x8e0 kernel/sched/core.c:6622
> > >>> schedule+0x51/0x80 kernel/sched/core.c:6701
> > >>> schedule_preempt_disabled+0x10/0x20 kernel/sched/core.c:6760
> > >>> kthread+0x11c/0x1e0 kernel/kthread.c:369
> > >>> ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:308
> > >>>
> >
> >
> > I didn't see the beginning of this thread and I think the part of the
> > sysbot report that lists the patches/trees being used got cut off so
> > I'm not 100% sure what's in the kernel.
> >
> > In Linus's current tree we do set_task_comm in __kthread_create_on_node
> > after waiting on the kthread_create_info completion which is completed by
> > threadd(). At this time, kthread() has already done the complete() on the
> > kthread_create_info completion and started to run the threadfn function and
> > that could be running. So we can hit the race that way.
> >
> >
> > In linux next, from
> > https://git.kernel.org/pub/scm/linux/kernel/git/brauner/linux.git/log/?h=kernel.user_worker
> > we have:
> >
> > commit cf587db2ee0261c74d04f61f39783db88a0b65e4
> > Author: Mike Christie <[email protected]>
> > Date: Fri Mar 10 16:03:23 2023 -0600
> >
> > kernel: Allow a kernel thread's name to be set in copy_process
> >
> > and so now copy_process() sets the name before the taskfn is started, so we
> > shouldn't hit any races like above.
>
> Yeah, that looks like it should fix it.
>
> Afaict, this has no reproducer so there's no point in letting syzbot
> test on this. I've sent the pull request for the kernel user worker
> series on Friday. So I guess we'll see whether it's reproducible on
> v6.4-rc1.

To see if it still happens to tell syzbot about the fix, then it will
remind if it still happens with the fix or not. Otherwise everybody
will forget about this tomorrow ;)

#syz fix: kernel: Allow a kernel thread's name to be set in copy_process

Btw, a similar race will still be possible b/c it's possible to change
the name at any point by writing to /proc/self/task/[tid]/comm. But I
am not sure how provably dangerous it will be and there is a different
attitude towards fixing races proactively for different kernel
subsystems, so we will probably not report it.