Re: [PATCH v4 00/10] Add Kernel Concurrency Sanitizer (KCSAN)

From: Qian Cai
Date: Tue Nov 19 2019 - 14:51:07 EST

On Thu, 2019-11-14 at 19:02 +0100, 'Marco Elver' via kasan-dev wrote:
> This is the patch-series for the Kernel Concurrency Sanitizer (KCSAN).
> KCSAN is a sampling watchpoint-based *data race detector*. More details
> are included in **Documentation/dev-tools/kcsan.rst**. This patch-series
> only enables KCSAN for x86, but we expect adding support for other
> architectures is relatively straightforward (we are aware of
> experimental ARM64 and POWER support).

Just booting x86 systems because kcsan_setup_watchpoint() disabled hard irqs?

[ÂÂÂÂ8.926145][ÂÂÂÂT0] ------------[ cut here ]------------
[ÂÂÂÂ8.927850][ÂÂÂÂT0] DEBUG_LOCKS_WARN_ON(!current->hardirqs_enabled)
[ÂÂÂÂ80] WARNING: CPU: 0 PID: 0 at kernel/locking/lockdep.c:4406
check_flags.part.26+0x102/0x240
[ÂÂÂÂ8.933072][ÂÂÂÂT0] Modules linked in:
[ÂÂÂÂ8.933072][ÂÂÂÂT0] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.4.0-rc8-next-
20191119+ #2
[ÂÂÂÂ8.933072][ÂÂÂÂT0] Hardware name: HP ProLiant XL420 Gen9/ProLiant XL420
Gen9, BIOS U19 12/27/2015
[ÂÂÂÂ8.933072][ÂÂÂÂT0] RIP: 0010:check_flags.part.26+0x102/0x240
[ÂÂÂÂ8.933072][ÂÂÂÂT0] Code: 7b a2 e8 51 6d 15 00 44 8b 05 fa df 45 01 45 85 c0
0f 85 27 76 00 00 48 c7 c6 02 d6 3b a2 48 c7 c7 79 36 3b a2 e8 2f 9f f5 ff <0f>
e9 0d 76 00 00 65 48 8b 3c 25 40 3f 01 00 e8 89 f0 ff ff e8
[ÂÂÂÂ8.933072][ÂÂÂÂT0] RSP: 0000:ffffffffa2603860 EFLAGS: 00010086
[ÂÂÂÂ8.933072][ÂÂÂÂT0] RAX: 0000000000000000 RBX: ffffffffa2617b40 RCX:
0000000000000000
[ÂÂÂÂ8.933072][ÂÂÂÂT0] RDX: 0000000000000000 RSI: 0000000000000001 RDI:
0000000000000000
[ÂÂÂÂ8.933072][ÂÂÂÂT0] RBP: ffffffffa2603868 R08: 0000000000000000 R09:
0000ffffa27bcad4
[ÂÂÂÂ8.933072][ÂÂÂÂT0] R10: 0000ffffffffffff R11: 0000ffffa27bcad7 R12:
0000000000000168
[ÂÂÂÂ8.933072][ÂÂÂÂT0] R13: 0000000000092cc0 R14: 0000000000000246 R15:
ffffffffa1664c89
[ÂÂÂÂ8.933072][ÂÂÂÂT0] FS:ÂÂ0000000000000000(0000) GS:ffff8987f3000000(0000)
knlGS:0000000000000000
[ÂÂÂÂ8.933072][ÂÂÂÂT0] CS:ÂÂ0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ÂÂÂÂ8.933072][ÂÂÂÂT0] CR2: ffff898bfc9ff000 CR3: 000000033dc0e001 CR4:
00000000001606f0
[ÂÂÂÂ8.933072][ÂÂÂÂT0] Call Trace:
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂlock_is_held_type+0x66/0x13072][ÂÂÂÂT0]ÂÂ?
rcu_is_watching+0x79/0xa0
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂ? create_object+0x69/0x690
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂrcu_read_lock_sched_held+0x7f/0xa0
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂkmem_cache_alloc+0x3b2/0x420
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂ? create_object+0x69/0x690
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂcreate_object+0x69/0x690
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂ? find_next_bit+0x7b/0xa0
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂkmemleak_alloc_percpu+0xde/0x170
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂpcpu_alloc+0x683/0xc90
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂ__alloc_percpu+0x2d/0x40
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂalloc_vfsmnt+0xd1/0x380
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂvfs_create_mount+0x7f/0x2e0
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂ? proc_get_tree+0x4d/0x60
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂfc_mount+0x6d/0x80
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂpid_ns_prepare_proc+0x133/0x190
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂalloc_pid+0x5c3/0x600
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂcopy_process+0x1ca3/0x3480
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂ? __lock_acquire+0x739/0x25d0
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂ_do_fork+0xaa/0x9c0
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂ? rcu_blocking_is_gp+0x83/0xb0
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂ? synchronize_rcu_expedited+0x80/0x6c0
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂ? rcu_blocking_is_gp+0x83/0xb0
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂ? rest_init+0x381/0x381
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂkernel_thread+0xb0/0xe0
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂ? rest_init+0x381/0x381
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂrest_init+0x31/0x381
[ÂÂÂÂ8.933072][ÂÂÂst_init+0x17/0x29
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂstart_kernel+0x6ac/0x6d0
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂx86_64_start_reservations+0x24/0x26
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂx86_64_start_kernel+0xef/0xf6
[ÂÂÂÂ8.933072][ÂÂÂÂT0]ÂÂsecondary_startup_64+0xb6/0xc0
[ÂÂÂÂ8.933072][ÂÂÂÂT0] irq event stamp: 75594
[ÂÂÂÂ8.933072][ÂÂÂÂT0] hardirqs lastÂÂenabled at (75593): [<ffffffffa1203d52>]
trace_hardirqs_on_thunk+0x1a/0x1c
[ÂÂÂÂ8.933072][ÂÂÂÂT0] hardirqs last disabled at (75594): [<ffffffffa14b4f96>]
kcsan_setup_watchpoint+0x96/0x200
[ÂÂÂÂ8.933072][ÂÂÂÂT0] softirqs lastÂÂenabled at (75592): [<ffffffffa200034c>]
__do_softirq+0x34c/0x57c
[ÂÂÂÂ8.933072][ÂÂÂÂT0] softirqs last disabled at (75585): [<ffffffffa12c6fb2>]
irq_exit+0xa2/0xc0
[ÂÂÂÂ8.933072][ÂÂÂÂT0] ---[ end trace f4a667495da45c20 ]---
[ÂÂÂÂ8.933072][ÂÂÂÂT0] possible reason: unannotated irqs-on.
[ÂÂÂÂ8.933072][ÂÂÂÂT0] irq event stamp: 75594
[ÂÂÂÂ8.933072][ÂÂÂÂT0] hardirqs lastÂÂenabled at (75593): [<ffffffffa1203d52>]
trace_hardirqs_on_thunk+0x1a/0x1c
[ÂÂÂÂ8.933072][ÂÂÂÂT0] hardirqs last disabled at (75594): [<ffffffffa14b4f96>]
kcsan_setup_watchpoint+0x96/0x200
[ÂÂÂÂ8.933072][ÂÂÂÂT0] softirqs lastÂÂenabled at (75592): [<ffffffffa200034c>]
__do_softirq+0x34c/0x57c
[ÂÂÂÂ8.933072][ÂÂÂÂT0] softirqs last disabled at (75585): [<ffffffffa12c6fb2>]
irq_exit+0xa2/0xc0


>
> To gather early feedback, we announced KCSAN back in September, and have
> integrated the feedback where possible:
> http://lkml.kernel.org/r/CANpmjNPJ_bHjfLZCAPV23AXFfiPiyXXqqu72n6TgWzb2Gnu1eA@xxxxxxxxxxxxxx
>
> The current list of known upstream fixes for data races found by KCSAN
> can be found here:
> https://github.com/google/ktsan/wiki/KCSAN#upstream-fixes-of-data-races-found-by-kcsan
>
> We want to point out and acknowledge the work surrounding the LKMM,
> including several articles that motivate why data races are dangerous
> [1, 2], justifying a data race detector such as KCSAN.
>
> [1] https://lwn.net/Articles/793253/
> [2] https://lwn.net/Articles/799218/
>
> Race conditions vs. data races
> ------------------------------
>
> Race conditions are logic bugs, where unexpected interleaving of racing
> concurrent operations result in an erroneous state.
>
> Data races on the other hand are defined at the *memory model/language
> level*. Many data races are also harmful race conditions, which a tool
> like KCSAN reports! However, not all data races are race conditions and
> vice-versa. KCSAN's intent is to report data races according to the
> LKMM. A data race detector can only work at the memory model/language
> level.
>
> Deeper analysis, to find high-level race conditions only, requires
> conveying the intended kernel logic to a tool. This requires (1) the
> developer writing a specification or model of their code, and then (2)
> the tool verifying that the implementation matches. This has been done
> for small bits of code using model checkers and other formal methods,
> but does not scale to the level of what can be covered with a dynamic
> analysis based data race detector such as KCSAN.
>
> For reasons outlined in [1, 2], data races can be much more subtle, but
> can cause no less harm than high-level race conditions.
>
> Changelog
> ---------
> v4:
> * Major changes:
> - Optimizations resulting in performance improvement of 33% (on
> microbenchmark).
> - Deal with nested interrupts for atomic_next.
> - Simplify report.c (removing double-locking as well), in preparation
> for KCSAN_REPORT_VALUE_CHANGE_ONLY.
> - Add patch to introduce "data_race(expr)" macro.
> - Introduce KCSAN_REPORT_VALUE_CHANGE_ONLY option for further filtering of data
> races: if a conflicting write was observed via a watchpoint, only report the
> data race if a value change was observed as well. The option will be enabled
> by default on syzbot. (rcu-functions will be excluded from this filter at
> request of Paul McKenney.) Context:
> http://lkml.kernel.org/r/CANpmjNOepvb6+zJmDePxj21n2rctM4Sp4rJ66x_J-L1UmNK54A@xxxxxxxxxxxxxx
>
> v3: http://lkml.kernel.org/r/20191104142745.14722-1-elver@xxxxxxxxxx
> * Major changes:
> - Add microbenchmark.
> - Add instruction watchpoint skip randomization.
> - Refactor API and core runtime fast-path and slow-path. Compared to
> the previous version, with a default config and benchmarked using the
> added microbenchmark, this version is 3.8x faster.
> - Make __tsan_unaligned __alias of generic accesses.
> - Rename kcsan_{begin,end}_atomic ->
> kcsan_{nestable,flat}_atomic_{begin,end}
> - For filter list in debugfs.c use kmalloc+krealloc instead of
> kvmalloc.
> - Split Documentation into separate patch.
>
> v2: http://lkml.kernel.org/r/20191017141305.146193-1-elver@xxxxxxxxxx
> * Major changes:
> - Replace kcsan_check_access(.., {true, false}) with
> kcsan_check_{read,write}.
> - Change atomic-instrumented.h to use __atomic_check_{read,write}.
> - Use common struct kcsan_ctx in task_struct and for per-CPU interrupt
> contexts.
>
> v1: http://lkml.kernel.org/r/20191016083959.186860-1-elver@xxxxxxxxxx
>
> Marco Elver (10):
> kcsan: Add Kernel Concurrency Sanitizer infrastructure
> include/linux/compiler.h: Introduce data_race(expr) macro
> kcsan: Add Documentation entry in dev-tools
> objtool, kcsan: Add KCSAN runtime functions to whitelist
> build, kcsan: Add KCSAN build exceptions
> seqlock, kcsan: Add annotations for KCSAN
> seqlock: Require WRITE_ONCE surrounding raw_seqcount_barrier
> asm-generic, kcsan: Add KCSAN instrumentation for bitops
> locking/atomics, kcsan: Add KCSAN instrumentation
> x86, kcsan: Enable KCSAN for x86
>
> Documentation/dev-tools/index.rst | 1 +
> Documentation/dev-tools/kcsan.rst | 256 +++++++++
> MAINTAINERS | 11 +
> Makefile | 3 +-
> arch/x86/Kconfig | 1 +
> arch/x86/boot/Makefile | 2 +
> arch/x86/boot/compressed/Makefile | 2 +
> arch/x86/entry/vdso/Makefile | 3 +
> arch/x86/include/asm/bitops.h | 6 +-
> arch/x86/kernel/Makefile | 4 +
> arch/x86/kernel/cpu/Makefile | 3 +
> arch/x86/lib/Makefile | 4 +
> arch/x86/mm/Makefile | 4 +
> arch/x86/purgatory/Makefile | 2 +
> arch/x86/realmode/Makefile | 3 +
> arch/x86/realmode/rm/Makefile | 3 +
> drivers/firmware/efi/libstub/Makefile | 2 +
> include/asm-generic/atomic-instrumented.h | 393 +++++++-------
> include/asm-generic/bitops-instrumented.h | 18 +
> include/linux/compiler-clang.h | 9 +
> include/linux/compiler-gcc.h | 7 +
> include/linux/compiler.h | 57 +-
> include/linux/kcsan-checks.h | 97 ++++
> include/linux/kcsan.h | 115 ++++
> include/linux/sched.h | 4 +
> include/linux/seqlock.h | 51 +-
> init/init_task.c | 8 +
> init/main.c | 2 +
> kernel/Makefile | 6 +
> kernel/kcsan/Makefile | 11 +
> kernel/kcsan/atomic.h | 27 +
> kernel/kcsan/core.c | 626 ++++++++++++++++++++++
> kernel/kcsan/debugfs.c | 275 ++++++++++
> kernel/kcsan/encoding.h | 94 ++++
> kernel/kcsan/kcsan.h | 108 ++++
> kernel/kcsan/report.c | 320 +++++++++++
> kernel/kcsan/test.c | 121 +++++
> kernel/sched/Makefile | 6 +
> lib/Kconfig.debug | 2 +
> lib/Kconfig.kcsan | 118 ++++
> lib/Makefile | 3 +
> mm/Makefile | 8 +
> scripts/Makefile.kcsan | 6 +
> scripts/Makefile.lib | 10 +
> scripts/atomic/gen-atomic-instrumented.sh | 17 +-
> tools/objtool/check.c | 18 +
> 46 files changed, 2641 insertions(+), 206 deletions(-)
> create mode 100644 Documentation/dev-tools/kcsan.rst
> create mode 100644 include/linux/kcsan-checks.h
> create mode 100644 include/linux/kcsan.h
> create mode 100644 kernel/kcsan/Makefile
> create mode 100644 kernel/kcsan/atomic.h
> create mode 100644 kernel/kcsan/core.c
> create mode 100644 kernel/kcsan/debugfs.c
> create mode 100644 kernel/kcsan/encoding.h
> create mode 100644 kernel/kcsan/kcsan.h
> create mode 100644 kernel/kcsan/report.c
> create mode 100644 kernel/kcsan/test.c
> create mode 100644 lib/Kconfig.kcsan
> create mode 100644 scripts/Makefile.kcsan
>
> --
> 2.24.0.rc1.363.gb1bccd3e3d-goog
>