KCSAN: data-race in tick_nohz_stop_tick / tick_sched_timer

KCSAN: data-race in tick_nohz_stop_tick / tick_sched_timer

[Kaia Yadira]

Hello,

When using Syzkaller to fuzz the latest Linux kernel, the following
crash was triggered.

HEAD commit: a7904a538933 Linux 5.16-rc6
git tree: upstream
console output: KCSAN: data-race in tick_nohz_stop_tick / tick_nohz_stop_tick
kernel config: https://paste.ubuntu.com/p/QB39MJKWKb/plain/
Syzlang reproducer: https://paste.ubuntu.com/p/T25kYMrytM/plain/

If you fix this issue, please add the following tag to the commit:

Reported-by: Hypericum <hypericumperforatum4444@gmail.com>

I think there are two threads visiting the variable tick_do_timer_cpu
at kernel/time/tick-sched.c:191 and 872 without locking.

reproducer log: https://paste.ubuntu.com/p/942c3QpFDJ/plain/
report:
==================================================================
BUG: KCSAN: data-race in tick_nohz_stop_tick / tick_sched_timer

write to 0xffffffff85ebf1e0 of 4 bytes by task 0 on cpu 6:
 tick_nohz_stop_tick+0xa5/0x410 kernel/time/tick-sched.c:873
 __tick_nohz_idle_stop_tick kernel/time/tick-sched.c:1062 [inline]
 tick_nohz_idle_stop_tick+0xde/0x1a0 kernel/time/tick-sched.c:1083
 cpuidle_idle_call kernel/sched/idle.c:192 [inline]
 do_idle+0xe3/0x250 kernel/sched/idle.c:306
 cpu_startup_entry+0x15/0x20 kernel/sched/idle.c:403
 secondary_startup_64_no_verify+0xb1/0xbb

read to 0xffffffff85ebf1e0 of 4 bytes by interrupt on cpu 1:
 tick_sched_do_timer kernel/time/tick-sched.c:187 [inline]
 tick_sched_timer+0x41/0x210 kernel/time/tick-sched.c:1421
 __run_hrtimer+0x133/0x420 kernel/time/hrtimer.c:1685
 __hrtimer_run_queues kernel/time/hrtimer.c:1749 [inline]
 hrtimer_interrupt+0x36e/0xa80 kernel/time/hrtimer.c:1811
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1086 [inline]
 __sysvec_apic_timer_interrupt+0xa3/0x250 arch/x86/kernel/apic/apic.c:1103
 sysvec_apic_timer_interrupt+0x88/0xb0 arch/x86/kernel/apic/apic.c:1097
 asm_sysvec_apic_timer_interrupt+0x12/0x20
 native_safe_halt arch/x86/include/asm/irqflags.h:51 [inline]
 arch_safe_halt arch/x86/include/asm/irqflags.h:89 [inline]
 default_idle+0xb/0x10 arch/x86/kernel/process.c:733
 default_idle_call+0x28/0xd0 kernel/sched/idle.c:112
 cpuidle_idle_call kernel/sched/idle.c:194 [inline]
 do_idle+0xe8/0x250 kernel/sched/idle.c:306
 cpu_startup_entry+0x15/0x20 kernel/sched/idle.c:403
 secondary_startup_64_no_verify+0xb1/0xbb

value changed: 0x00000006 -> 0xffffffff

Reported by Kernel Concurrency Sanitizer on:
CPU: 1 PID: 0 Comm: swapper/1 Not tainted 5.16.0-rc8+ #11
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.13.0-1ubuntu1.1 04/01/2014
==================================================================

Re: KCSAN: data-race in tick_nohz_stop_tick / tick_sched_timer

[Dmitry Vyukov]

On Tue, 11 Jan 2022 at 14:41, Kaia Yadira
<hypericumperforatum4444@gmail.com> wrote:
>
> Hello,

Hi Kaia, kvartet,

You started sending similarly looking reports around the same time.
Please share what you are doing/why and what's your goal? The issue is
that some of these reports may need some pre-moderation before dumping
onto kernel mailing lists.


> When using Syzkaller to fuzz the latest Linux kernel, the following
> crash was triggered.
>
> HEAD commit: a7904a538933 Linux 5.16-rc6
> git tree: upstream
> console output: KCSAN: data-race in tick_nohz_stop_tick / tick_nohz_stop_tick
> kernel config: https://paste.ubuntu.com/p/QB39MJKWKb/plain/
> Syzlang reproducer: https://paste.ubuntu.com/p/T25kYMrytM/plain/
>
> If you fix this issue, please add the following tag to the commit:
>
> Reported-by: Hypericum <hypericumperforatum4444@gmail.com>
>
> I think there are two threads visiting the variable tick_do_timer_cpu
> at kernel/time/tick-sched.c:191 and 872 without locking.
>
> reproducer log: https://paste.ubuntu.com/p/942c3QpFDJ/plain/
> report:
> ==================================================================
> BUG: KCSAN: data-race in tick_nohz_stop_tick / tick_sched_timer
>
> write to 0xffffffff85ebf1e0 of 4 bytes by task 0 on cpu 6:
>  tick_nohz_stop_tick+0xa5/0x410 kernel/time/tick-sched.c:873
>  __tick_nohz_idle_stop_tick kernel/time/tick-sched.c:1062 [inline]
>  tick_nohz_idle_stop_tick+0xde/0x1a0 kernel/time/tick-sched.c:1083
>  cpuidle_idle_call kernel/sched/idle.c:192 [inline]
>  do_idle+0xe3/0x250 kernel/sched/idle.c:306
>  cpu_startup_entry+0x15/0x20 kernel/sched/idle.c:403
>  secondary_startup_64_no_verify+0xb1/0xbb
>
> read to 0xffffffff85ebf1e0 of 4 bytes by interrupt on cpu 1:
>  tick_sched_do_timer kernel/time/tick-sched.c:187 [inline]
>  tick_sched_timer+0x41/0x210 kernel/time/tick-sched.c:1421
>  __run_hrtimer+0x133/0x420 kernel/time/hrtimer.c:1685
>  __hrtimer_run_queues kernel/time/hrtimer.c:1749 [inline]
>  hrtimer_interrupt+0x36e/0xa80 kernel/time/hrtimer.c:1811
>  local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1086 [inline]
>  __sysvec_apic_timer_interrupt+0xa3/0x250 arch/x86/kernel/apic/apic.c:1103
>  sysvec_apic_timer_interrupt+0x88/0xb0 arch/x86/kernel/apic/apic.c:1097
>  asm_sysvec_apic_timer_interrupt+0x12/0x20
>  native_safe_halt arch/x86/include/asm/irqflags.h:51 [inline]
>  arch_safe_halt arch/x86/include/asm/irqflags.h:89 [inline]
>  default_idle+0xb/0x10 arch/x86/kernel/process.c:733
>  default_idle_call+0x28/0xd0 kernel/sched/idle.c:112
>  cpuidle_idle_call kernel/sched/idle.c:194 [inline]
>  do_idle+0xe8/0x250 kernel/sched/idle.c:306
>  cpu_startup_entry+0x15/0x20 kernel/sched/idle.c:403
>  secondary_startup_64_no_verify+0xb1/0xbb
>
> value changed: 0x00000006 -> 0xffffffff
>
> Reported by Kernel Concurrency Sanitizer on:
> CPU: 1 PID: 0 Comm: swapper/1 Not tainted 5.16.0-rc8+ #11
> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
> 1.13.0-1ubuntu1.1 04/01/2014
> ==================================================================
>
> --
> You received this message because you are subscribed to the Google Groups "syzkaller-bugs" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to syzkaller-bugs+unsubscribe@googlegroups.com.
> To view this discussion on the web visit https://groups.google.com/d/msgid/syzkaller-bugs/CACDmwr_b0Z6JK2M6i6RZ4Qg3wb1uqG0NrybQ9mR2iw5QJT8XoA%40mail.gmail.com.

Re: KCSAN: data-race in tick_nohz_stop_tick / tick_sched_timer

[Dmitry Vyukov]

On Tue, 11 Jan 2022 at 17:56, Kaia Yadira
<hypericumperforatum4444@gmail.com> wrote:
>
> I'm sorry. They are similar but I can't tell if they are the same bug,
> so I report them individually.

+CC list back

I did not mean that you report similar bugs. I meant that you and
kvartet seem to be following the same process. There are several
complaints about the quality of reports. So I am wondering what you
are doing/why/what's your goal.

Hao Sun, you are CCed on all emails, maybe you can shed some light on this?

Re: KCSAN: data-race in tick_nohz_stop_tick / tick_sched_timer

[Hao Sun]

Dmitry Vyukov <dvyukov@google.com> 于2022年1月12日周三 01:18写道：
>
> On Tue, 11 Jan 2022 at 17:56, Kaia Yadira
> <hypericumperforatum4444@gmail.com> wrote:
> >
> > I'm sorry. They are similar but I can't tell if they are the same bug,
> > so I report them individually.
>
> +CC list back
>
> I did not mean that you report similar bugs. I meant that you and
> kvartet seem to be following the same process. There are several
> complaints about the quality of reports. So I am wondering what you
> are doing/why/what's your goal.
>
> Hao Sun, you are CCed on all emails, maybe you can shed some light on this?

Hi Dmitry,

I'm on holiday and ignored these emails.
kvartet is an acquaintance of mine, I have no idea who Kaia is.
I have little knowledge of their actions. They may be new to the
kernel community and may not understand the rules in reporting bugs

Maybe we should add some `WARNING` in Syzkaller docs, e.g.,
`how_to_report_bug.md`, to tell people to polish their reports before
sending them out.
Or maybe we should just suppress all the `task-hung` and `kcsan`
reports in Syzkaller by default, enable them manually if the user
knows what they are doing.

Hao

Re: KCSAN: data-race in tick_nohz_stop_tick / tick_sched_timer

[Dmitry Vyukov]

On Wed, 12 Jan 2022 at 02:39, Hao Sun <sunhao.th@gmail.com> wrote:
>
> Dmitry Vyukov <dvyukov@google.com> 于2022年1月12日周三 01:18写道：
> >
> > On Tue, 11 Jan 2022 at 17:56, Kaia Yadira
> > <hypericumperforatum4444@gmail.com> wrote:
> > >
> > > I'm sorry. They are similar but I can't tell if they are the same bug,
> > > so I report them individually.
> >
> > +CC list back
> >
> > I did not mean that you report similar bugs. I meant that you and
> > kvartet seem to be following the same process. There are several
> > complaints about the quality of reports. So I am wondering what you
> > are doing/why/what's your goal.
> >
> > Hao Sun, you are CCed on all emails, maybe you can shed some light on this?
>
> Hi Dmitry,
>
> I'm on holiday and ignored these emails.
> kvartet is an acquaintance of mine, I have no idea who Kaia is.
> I have little knowledge of their actions. They may be new to the
> kernel community and may not understand the rules in reporting bugs
>
> Maybe we should add some `WARNING` in Syzkaller docs, e.g.,
> `how_to_report_bug.md`, to tell people to polish their reports before
> sending them out.

Hi Hao,

Thanks for the info.

We've already extended how_to_report_bug.md with some warning:
https://github.com/google/syzkaller/commit/ca0f51ac4a404a5378464e91c42eca8c1e78e21a
But it does not mention KCSAN/KMSAN yet, as these reports come in later.

> Or maybe we should just suppress all the `task-hung` and `kcsan`
> reports in Syzkaller by default, enable them manually if the user
> knows what they are doing.

This is a good idea.
We will need to figure out details, and this will require some coding.