Re: [PATCH v4 01/10] kcsan: Add Kernel Concurrency Sanitizer infrastructure

[Marco Elver <elver@google.com>]

On Fri, 3 Jan 2020 at 06:13, Qian Cai <cai@lca.pw> wrote:
>
>
>
> > On Nov 14, 2019, at 1:02 PM, 'Marco Elver' via kasan-dev <kasan-dev@googlegroups.com> wrote:
> > +static noinline void kcsan_setup_watchpoint(const volatile void *ptr,
> > +                                         size_t size, bool is_write)
> > +{
> > +     atomic_long_t *watchpoint;
> > +     union {
> > +             u8 _1;
> > +             u16 _2;
> > +             u32 _4;
> > +             u64 _8;
> > +     } expect_value;
> > +     bool value_change = false;
> > +     unsigned long ua_flags = user_access_save();
> > +     unsigned long irq_flags;
> > +
> > +     /*
> > +      * Always reset kcsan_skip counter in slow-path to avoid underflow; see
> > +      * should_watch().
> > +      */
> > +     reset_kcsan_skip();
> > +
> > +     if (!kcsan_is_enabled())
> > +             goto out;
> > +
> > +     if (!check_encodable((unsigned long)ptr, size)) {
> > +             kcsan_counter_inc(KCSAN_COUNTER_UNENCODABLE_ACCESSES);
> > +             goto out;
> > +     }
> > +
> > +     /*
> > +      * Disable interrupts & preemptions to avoid another thread on the same
> > +      * CPU accessing memory locations for the set up watchpoint; this is to
> > +      * avoid reporting races to e.g. CPU-local data.
> > +      *
> > +      * An alternative would be adding the source CPU to the watchpoint
> > +      * encoding, and checking that watchpoint-CPU != this-CPU. There are
> > +      * several problems with this:
> > +      *   1. we should avoid stealing more bits from the watchpoint encoding
> > +      *      as it would affect accuracy, as well as increase performance
> > +      *      overhead in the fast-path;
> > +      *   2. if we are preempted, but there *is* a genuine data race, we
> > +      *      would *not* report it -- since this is the common case (vs.
> > +      *      CPU-local data accesses), it makes more sense (from a data race
> > +      *      detection point of view) to simply disable preemptions to ensure
> > +      *      as many tasks as possible run on other CPUs.
> > +      */
> > +     local_irq_save(irq_flags);
>
> Enabling KCSAN will now generate a warning during boot here.
>
> Config (need to deselect KASAN and select KCSAN):
>
> https://raw.githubusercontent.com/cailca/linux-mm/master/x86.config

Thanks, I'll look into KCSAN + lockdep compatibility. It's probably
missing some KCSAN_SANITIZE := n in some Makefile.

> [   13.358813][    T0] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
> [   13.361606][    T0] Speculative Store Bypass: Vulnerable
> [   13.363254][    T0] TAA: Vulnerable: Clear CPU buffers attempted, no microcode
> [   13.366836][    T0] MDS: Vulnerable: Clear CPU buffers attempted, no microcode
> [   13.369877][    T0] debug: unmapping init [mem 0xffffffff8dd83000-0xffffffff8dd87fff]
> [   13.415028][    T1] ------------[ cut here ]------------
> [   13.416814][    T1] DEBUG_LOCKS_WARN_ON(!current->hardirqs_enabled)
> [   13.416814][    T1] WARNING: CPU: 0 PID: 1 at kernel/locking/lockdep.c:4406 check_flags.part.26+0x102/0x240
> [   13.416814][    T1] Modules linked in:
> [   13.416814][    T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.5.0-rc2-next-20191220+ #4
> [   13.416814][    T1] Hardware name: HP ProLiant DL580 Gen9/ProLiant DL580 Gen9, BIOS U17 07/21/2016
> [   13.416814][    T1] RIP: 0010:check_flags.part.26+0x102/0x240
> [   13.416814][    T1] Code: bc 8d e8 51 a1 15 00 44 8b 05 2a a0 46 01 45 85 c0 0f 85 57 76 00 00 48 c7 c6 5d fa 7b 8d 48 c7 c7 b1 54 7b 8d e8 10 91 f5 ff <0f> 0b e9 3d 76 00 00 65 48 8b 3c 25 40 7f 01 00 e8 89 f0 ff ff e8
> [   13.416814][    T1] RSP: 0000:ffff9d3206287ce8 EFLAGS: 00010082
> [   13.416814][    T1] RAX: 0000000000000000 RBX: ffff8e5b8541e040 RCX: 0000000000000000
> [   13.416814][    T1] RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000000
> [   13.416814][    T1] RBP: ffff9d3206287cf0 R08: 0000000000000000 R09: 0000ffff8dbcc254
> [   13.416814][    T1] R10: 0000ffffffffffff R11: 0000ffff8dbcc257 R12: 0000000000000235
> [   13.416814][    T1] R13: 0000000000000000 R14: 0000000000000246 R15: 000000000000001b
> [   13.416814][    T1] FS:  0000000000000000(0000) GS:ffff8e61e3200000(0000) knlGS:0000000000000000
> [   13.416814][    T1] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [   13.416814][    T1] CR2: ffff8e79f07ff000 CR3: 0000001284c0e001 CR4: 00000000003606f0
> [   13.416814][    T1] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [   13.416814][    T1] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [   13.416814][    T1] Call Trace:
> [   13.416814][    T1]  lock_is_held_type+0x66/0x160
> [   13.416814][    T1]  ___might_sleep+0xc1/0x1d0
> [   13.416814][    T1]  __might_sleep+0x5b/0xa0
> [   13.416814][    T1]  slab_pre_alloc_hook+0x7b/0xa0
> [   13.416814][    T1]  __kmalloc_node+0x60/0x300
> [   13.416814   T1]  ? alloc_cpumask_var_node+0x44/0x70
> [   13.416814][    T1]  ? topology_phys_to_logical_die+0x7e/0x180
> [   13.416814][    T1]  alloc_cpumask_var_node+0x44/0x70
> [   13.416814][    T1]  zalloc_cpumask_var+0x2a/0x40
> [   13.416814][    T1]  native_smp_prepare_cpus+0x246/0x425
> [   13.416814][    T1]  kernel_init_freeable+0x1b8/0x496
> [   13.416814][    T1]  ? rest_init+0x381/0x381
> [   13.416814][    T1]  kernel_init+0x18/0x17f
> [   13.416814][    T1]  ? rest_init+0x381/0x381
> [   13.416814][    T1]  ret_from_fork+0x3a/0x50
> [   13.416814][    T1] irq event stamp: 910
> [   13.416814][    T1] hardirqs last  enabled at (909): [<ffffffff8d1240f3>] _raw_write_unlock_irqrestore+0x53/0x57
> [   13.416814][    T1] hardirqs last disabled at (910): [<ffffffff8c8bba76>] kcsan_setup_watchpoint+0x96/0x460
> [   13.416814][    T1] softirqs last  enabled at (0): [<ffffffff8c6b697a>] copy_process+0x11fa/0x34f0
> [   13.416814][    T1] softirqs last disabled at (0): [<0000000000000000>] 0x0
> [   13.416814][    T1] ---[ end trace 7d1df66da055aa92 ]---
> [   13.416814][    T1] possible reason: unannotated irqs-on.
> [   13.416814][ent stamp: 910
> [   13.416814][    T1] hardirqs last  enabled at (909): [<ffffffff8d1240f3>] _raw_write_unlock_irqrestore+0x53/0x57
> [   13.416814][    T1] hardirqs last disabled at (910): [<ffffffff8c8bba76>] kcsan_setup_watchpoint+0x96/0x460
> [   13.416814][    T1] softirqs last  enabled at (0): [<ffffffff8c6b697a>] copy_process+0x11fa/0x34f0
> [   13.416814][    T1] softirqs last disabled at (0): [<0000000000000000>] 0x0
>
>
> The other issue is that the system is unable to boot due to endless of those messages.

Apart from fixing the data races, I can add a feature to KCSAN to
limit reporting too often (will send patch).

> [   17.976814][  T578] Reported by Kernel Concurrency Sanitizer on:
> [   17.976814][  T578] CPU: 12 PID: 578 Comm: pgdatinit1 Tainted: G        W         5.5.0-rc2-next-20191220+ #4
> [   17.976814][  T578] Hardware name: HP ProLiant DL580 Gen9/ProLiant DL580 Gen9, BIOS U17 07/21/2016
> [   17.976814][  T578] ==================================================================
> [   17.976814][  T578] ==================================================================
> [   17.976814][  T578] BUG: KCSAN: data-race in __change_page_attr / __change_page_attr
> [   17.976814][  T578]
> [   17.976814][  T578] write to 0xffffffff8dda0de0 of 8 bytes by task 577 on cpu 2:
> [   17.976814][  T578]  __change_page_attr+0xef7/0x16a0
> [   17.976814][  T578]  __change_page_attr_set_clr+0xec/0x4f0
> [   17.97681pages_np+0xcc/0x100
> [   17.976814][  T578]  __kernel_map_pages+0xd6/0xdb
> [   17.976814][  T578]  __free_pages_ok+0x1a8/0x730
> [   17.976814][  T578]  __free_pages+0x51/0x90
> [   17.976814][  T578]  __free_pages_core+0x1c7/0x2c0
> [   17.976814][  T578]  deferred_free_range+0x59/0x8f
> [   17.976814][  T578]  deferred_init_maxorder+0x1d6/0x21d
> [   17.976814][  T578]  deferred_init_memmap+0x14a/0x1c1
> [   17.976814][  T578]  kthread+0x1e0/0x200
> [   17.976814][  T578]  ret_from_fork+0x3a/0x50
> [   17.976814][  T578]
> [   17.976814][  T578] read to 0xffffffff8dda0de0 of 8 bytes by task 578 on cpu 12:
> [   17.976814][  T578]  __change_page_attr+0xed1/0x16a0
> [   17.976814][  T578]  __change_page_attr_set_clr+0xec/0x4f0
> [   17.976814][  T578]  __set_pages_np+0xcc/0x100
> [   17.976814][  T578]  __kernel_map_pages+0xd6/0xdb
> [   17.976814][  T578]  __free_pages_ok+0x1a8/0x730
> [   17.976814][  T578]  __free_pages+0x51/0x90
> [   17.976814][  T578]  __free_pages_core+0x1c7/0x2c0
> [   17.976814][  T578]  deferred_free_range+0x59/0x8f
> [   17.976814][  T578]  deferred_init_maxorder+0x1aa/0x21d
> [   17.976814][  T578]  deferred_init_memmap+0x14a/0x1c1
> [   17.976814][  T578]  kthread+0x1e0/0x200
> [   17.976814][  T578]  ret_from_fork+0x3a/0x50
>
> # ./scripts/faddr2line vmlinux __change_page_attr+0xef7/0x16a0
> __change_page_attr+0xef7/0x16a0:
> static_protections at arch/x86/mm/pat/set_memory.c:528
> (inlined by) __change_page_attr at arch/x86/mm/pat/set_memory.c:1516
>
> # ./scripts/faddr2line vmlinux __change_page_attr+0xed1/0x16a0
> __change_page_attr+0xed1/0x16a0:
> cpa_inc_4k_install at arch/x86/mm/pat/set_memory.c:131
> (inlined by) __change_page_attr at arch/x86/mm/pat/set_memory.c:1514

Thanks,
-- Marco