Re: Kernel Concurrency Sanitizer (KCSAN)

From: Daniel Axtens
Date: Tue Oct 01 2019 - 10:50:12 EST


Hi Marco,

> We would like to share a new data-race detector for the Linux kernel:
> Kernel Concurrency Sanitizer (KCSAN) --
> https://github.com/google/ktsan/wiki/KCSAN (Details:
> https://github.com/google/ktsan/blob/kcsan/Documentation/dev-tools/kcsan.rst)

This builds and begins to boot on powerpc, which is fantastic.

I'm seeing a lot of reports for locks are changed while being watched by
kcsan, so many that it floods the console and stalls the boot.

I think, if I've understood correctly, that this is because powerpc
doesn't use the queued lock implementation for its spinlock but rather
its own assembler locking code. This means the writes aren't
instrumented by the compiler, while some reads are. (see
__arch_spin_trylock in e.g. arch/powerpc/include/asm/spinlock.h)

Would the correct way to deal with this be for the powerpc code to call
out to __tsan_readN/__tsan_writeN before invoking the assembler that
reads and writes the lock?

Regards,
Daniel


[ 24.612864] ==================================================================
[ 24.614188] BUG: KCSAN: racing read in __spin_yield+0xa8/0x180
[ 24.614669]
[ 24.614799] race at unknown origin, with read to 0xc00000003fff9d00 of 4 bytes by task 449 on cpu 11:
[ 24.616024] __spin_yield+0xa8/0x180
[ 24.616377] _raw_spin_lock_irqsave+0x1a8/0x1b0
[ 24.616850] release_pages+0x3a0/0x880
[ 24.617203] free_pages_and_swap_cache+0x13c/0x220
[ 24.622548] tlb_flush_mmu+0x210/0x2f0
[ 24.622979] tlb_finish_mmu+0x12c/0x240
[ 24.623286] exit_mmap+0x138/0x2c0
[ 24.623779] mmput+0xe0/0x330
[ 24.624504] do_exit+0x65c/0x1050
[ 24.624835] do_group_exit+0xb4/0x210
[ 24.625458] __wake_up_parent+0x0/0x80
[ 24.625985] system_call+0x5c/0x70
[ 24.626415]
[ 24.626651] Reported by Kernel Concurrency Sanitizer on:
[ 24.628329] CPU: 11 PID: 449 Comm: systemd-bless-b Not tainted 5.3.0-00007-gad29ff6c190d-dirty #9
[ 24.629508] ==================================================================

[ 24.672860] ==================================================================
[ 24.675901] BUG: KCSAN: data-race in _raw_spin_lock_irqsave+0x13c/0x1b0 and _raw_spin_unlock_irqrestore+0x94/0x100
[ 24.680847]
[ 24.682743] write to 0xc0000001ffeefe00 of 4 bytes by task 455 on cpu 5:
[ 24.683402] _raw_spin_unlock_irqrestore+0x94/0x100
[ 24.684593] release_pages+0x250/0x880
[ 24.685148] free_pages_and_swap_cache+0x13c/0x220
[ 24.686068] tlb_flush_mmu+0x210/0x2f0
[ 24.690190] tlb_finish_mmu+0x12c/0x240
[ 24.691082] exit_mmap+0x138/0x2c0
[ 24.693216] mmput+0xe0/0x330
[ 24.693597] do_exit+0x65c/0x1050
[ 24.694170] do_group_exit+0xb4/0x210
[ 24.694658] __wake_up_parent+0x0/0x80
[ 24.696230] system_call+0x5c/0x70
[ 24.700414]
[ 24.712991] read to 0xc0000001ffeefe00 of 4 bytes by task 454 on cpu 20:
[ 24.714419] _raw_spin_lock_irqsave+0x13c/0x1b0
[ 24.715018] pagevec_lru_move_fn+0xfc/0x1d0
[ 24.715527] __lru_cache_add+0x124/0x1a0
[ 24.716072] lru_cache_add+0x30/0x50
[ 24.716411] add_to_page_cache_lru+0x134/0x250
[ 24.717938] mpage_readpages+0x220/0x3f0
[ 24.719737] blkdev_readpages+0x50/0x80
[ 24.721891] read_pages+0xb4/0x340
[ 24.722834] __do_page_cache_readahead+0x318/0x350
[ 24.723290] force_page_cache_readahead+0x150/0x280
[ 24.724391] page_cache_sync_readahead+0xe4/0x110
[ 24.725087] generic_file_buffered_read+0xa20/0xdf0
[ 24.727003] generic_file_read_iter+0x220/0x310
[ 24.728906]
[ 24.730044] Reported by Kernel Concurrency Sanitizer on:
[ 24.732185] CPU: 20 PID: 454 Comm: systemd-gpt-aut Not tainted 5.3.0-00007-gad29ff6c190d-dirty #9
[ 24.734317] ==================================================================


>
> Thanks,
> -- Marco