Date:   Tue, 3 Mar 2020 22:55:02 -0500
From:   Qian Cai <cai@....pw>
To:     Matthew Wilcox <willy@...radead.org>
Cc:     paulmck@...nel.org, elver@...gle.com, linux-kernel@...r.kernel.org
Subject: Re: [PATCH -next] lib: disable KCSAN for XArray



> On Mar 3, 2020, at 10:33 PM, Matthew Wilcox <willy@...radead.org> wrote:
> 
> On Tue, Mar 03, 2020 at 10:15:51PM -0500, Qian Cai wrote:
>> Functions like xas_find_marked(), xas_set_mark(), and xas_clear_mark()
>> could happen concurrently result in data races, but those operate only
>> on a single bit that are pretty much harmless. For example,
> 
> Those aren't data races.  The writes are protected by a spinlock and the
> reads by the RCU read lock.  If the tool can't handle RCU protection,
> it's not going to be much use.
> 

Maybe the commit log is a bit confusing if you did not look at the example closely
enough. It is actually one read and one write result in data races where one spin_lock()
and one rcu_read_lock()  can’t prevent that from happening. We also have,

[19522.548668][T39646] BUG: KCSAN: data-race in xas_clear_mark / xas_find_marked 
[19522.583776][T39646]  
[19522.593816][T39646] write to 0xffff9ffb56c5c238 of 8 bytes by interrupt on cpu 16: 
[19522.628560][T39646]  xas_clear_mark+0x8e/0x1a0 
[19522.648993][T39646]  __xa_clear_mark+0xe7/0x110 
[19522.669367][T39646]  test_clear_page_writeback+0x3e9/0x712 [19522.694638][T39646]  end_page_writeback+0xaa/0x2b0 
[19522.716850][T39646]  iomap_finish_ioend+0x213/0x3b0 
[19522.740070][T39646]  iomap_writepage_end_bio+0x41/0x50 
[19522.763835][T39646]  bio_endio+0x297/0x560 
[19522.782608][T39646]  dec_pending+0x218/0x430 [dm_mod] 
[19522.805389][T39646]  clone_endio+0xe4/0x2c0 [dm_mod] 
[19522.828014][T39646]  bio_endio+0x297/0x560 
[19522.846681][T39646]  blk_update_request+0x201/0x920 
[19522.868929][T39646]  scsi_end_request+0x6b/0x4b0 
[19522.889924][T39646]  scsi_io_completion+0xb7/0x7e0 
[19522.911744][T39646]  scsi_finish_command+0x1ed/0x2a0 
[19522.934411][T39646]  scsi_softirq_done+0x1c9/0x1d0 
[19522.956357][T39646]  blk_done_softirq+0x181/0x1d0 
[19522.977796][T39646]  __do_softirq+0xd9/0x57c 
[19522.997300][T39646]  irq_exit+0xa2/0xc0 
[19523.015469][T39646]  do_IRQ+0x87/0x180 
[19523.032848][T39646]  ret_from_intr+0x0/0x42 
[19523.054251][T39646]  delay_tsc+0x46/0x80 
[19523.074662][T39646]  __const_udelay+0x3c/0x40 
[19523.095161][T39646]  __udelay+0x10/0x20 
[19523.113321][T39646]  kcsan_setup_watchpoint+0x1ec/0x3a0 
[19523.137486][T39646]  __tsan_read8+0xf1/0x110 
[19523.156973][T39646]  xas_find_marked+0xe9/0x750 
[19523.177267][T39646]  find_get_pages_range_tag+0x1bf/0xa90 
[19523.201945][T39646]  pagevec_lookup_range_tag+0x46/0x70 
[19523.226242][T39646]  __filemap_fdatawait_range+0xbb/0x270 
[19523.250977][T39646]  file_write_and_wait_range+0xe0/0x100 
[19523.276077][T39646]  xfs_file_fsync+0xeb/0x450 [xfs] 
[19523.298789][T39646]  vfs_fsync_range+0x71/0x110 
[19523.320550][T39646]  xfs_file_buffered_aio_write+0x6cf/0x790 [xfs] 
[19523.350421][T39646]  xfs_file_write_iter+0x232/0x2d0 [xfs] 
[19523.375536][T39646]  do_iter_readv_writev+0x321/0x400 
[19523.398811][T39646]  do_iter_write+0xdf/0x2b0 
[19523.418758][T39646]  vfs_writev+0xe6/0x170 
[19523.437516][T39646]  do_writev+0xa8/0x140 
[19523.455844][T39646]  __x64_sys_writev+0x4e/0x60 
[19523.476515][T39646]  do_syscall_64+0x91/0xb05 
[19523.496441][T39646]  entry_SYSCALL_64_after_hwframe+0x49/0xbe 
[19523.522946][T39646]  
[19523.533125][T39646] read to 0xffff9ffb56c5c238 of 8 bytes by task 39646 on cpu 16: 
[19523.570758][T39646]  xas_find_marked+0xe9/0x750 
[19523.594276][T39646]  find_get_pages_range_tag+0x1bf/0xa90 
[19523.618877][T39646]  pagevec_lookup_range_tag+0x46/0x70 
[19523.642674][T39646]  __filemap_fdatawait_range+0xbb/0x270 
[19523.667295][T39646]  file_write_and_wait_range+0xe0/0x100 
[19523.692394][T39646]  xfs_file_fsync+0xeb/0x450 [xfs] 
[19523.715149][T39646]  vfs_fsync_range+0x71/0x110 
[19523.736239][T39646]  xfs_file_buffered_aio_write+0x6cf/0x790 [xfs] 
[19523.765345][T39646]  xfs_file_write_iter+0x232/0x2d0 [xfs] 
[19523.791398][T39646]  do_iter_readv_writev+0x321/0x400 
[19523.814709][T39646]  do_iter_write+0xdf/0x2b0 
[19523.834576][T39646]  vfs_writev+0xe6/0x170 
[19523.853486][T39646]  do_writev+0xa8/0x140 
[19523.871952][T39646]  __x64_sys_writev+0x4e/0x60 
[19523.893148][T39646]  do_syscall_64+0x91/0xb05 
[19523.914075][T39646]  entry_SYSCALL_64_after_hwframe+0x49/0xbe 


[19648.209937][T39683] BUG: KCSAN: data-race in find_get_pages_range_tag / xas_set_mark 
[19648.248321][T39683]  
[19648.258683][T39683] write to 0xffffa001c3340238 of 8 bytes by task 39682 on cpu 25: 
[19648.295245][T39683]  xas_set_mark+0x8e/0x190 
[19648.315514][T39683]  __test_set_page_writeback+0x5de/0x8c0 
[19648.341697][T39683]  iomap_writepage_map+0x8c6/0xf90 
[19648.364916][T39683]  iomap_do_writepage+0x12b/0x450 
[19648.388367][T39683]  write_cache_pages+0x523/0xb20 
[19648.410232][T39683]  iomap_writepages+0x47/0x80 
[19648.431404][T39683]  xfs_vm_writepages+0xc7/0x100 [xfs] 
[19648.455333][T39683]  do_writepages+0x5e/0x130 
[19648.476105][T39683]  __filemap_fdatawrite_range+0x19e/0x1f0 
[19648.502048][T39683]  file_write_and_wait_range+0xc0/0x100 
[19648.527175][T39683]  xfs_file_fsync+0xeb/0x450 [xfs] 
[19648.549886][T39683]  vfs_fsync_range+0x71/0x110 
[19648.570508][T39683]  __x64_sys_msync+0x210/0x2a0 
[19648.591742][T39683]  do_syscall_64+0x91/0xb05 
[19648.612093][T39683]  entry_SYSCALL_64_after_hwframe+0x49/0xbe 
[19648.638410][T39683]  
[19648.648486][T39683] read to 0xffffa001c3340238 of 8 bytes by task 39683 on cpu 26: 
[19648.684048][T39683]  find_get_pages_range_tag+0x549/0xa90 
xas_for_each_marked() —> xas_find_marked()
[19648.710117][T39683]  pagevec_lookup_range_tag+0x46/0x70 
[19648.737531][T39683]  __filemap_fdatawait_range+0xbb/0x270 
[19648.762541][T39683]  file_write_and_wait_range+0xe0/0x100 
[19648.787436][T39683]  xfs_file_fsync+0xeb/0x450 [xfs] 
[19648.810136][T39683]  vfs_fsync_range+0x71/0x110 
[19648.830827][T39683]  __x64_sys_msync+0x210/0x2a0 
[19648.852022][T39683]  do_syscall_64+0x91/0xb05 
[19648.871962][T39683]  entry_SYSCALL_64_after_hwframe+0x49/0xbe 
[19648.899496][T39683]  
[19648.909496][T39683] 1 lock held by doio/39683: 
[19648.930880][T39683]  #0: ffffffffaf286cc0 (rcu_read_lock){....}, at: find_get_pages_range_tag+0x10f/0xa90 
[19648.976219][T39683] irq event stamp: 2463763 
[19648.996565][T39683] hardirqs last  enabled at (2463763): [<ffffffffade03ec2>] trace_hardirqs_on_thunk+0x1a/0x1c 
[19649.043090][T39683] hardirqs last disabled at (2463761): [<ffffffffaec002e7>] __do_softirq+0x2e7/0x57c 
[19649.087414][T39683] softirqs last  enabled at (2463762): [<ffffffffaec0034c>] __do_softirq+0x34c/0x57c 
[19649.129838][T39683] softirqs last disabled at (2463635): [<ffffffffadec69f2>] irq_exit+0xa2/0xc0

Powered by blists - more mailing lists