BUG: Data race reported by TSan in kvrocks

[PragmaTwice]

Search before asking

• I had searched in the issues and found no similar issues.

Version

unstable, linux

Minimal reproduce step

./build.sh build --unittest -DENABLE_TSAN=ON
./build/unittest

What did you expect to see?

No TSan report.

What did you see instead?

Selected TSan log in unittest:

WARNING: ThreadSanitizer: data race (pid=14679)
  Read of size 1 at 0x7b7c0000673b by thread T1:
    #0 memcmp <null> (libtsan.so.0+0x67cb3)
    #1 rocksdb::Slice::compare(rocksdb::Slice const&) const /home/runner/work/incubator-kvrocks/incubator-kvrocks/build/_deps/rocksdb-src/include/rocksdb/slice.h:250 (unittest+0x5d75ef)
    #2 Compare /home/runner/work/incubator-kvrocks/incubator-kvrocks/build/_deps/rocksdb-src/util/comparator.cc:34 (unittest+0x5d75ef)
    #3 Engine::SubKeyFilter::Filter(int, rocksdb::Slice const&, rocksdb::Slice const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >*, bool*) const /home/runner/work/incubator-kvrocks/incubator-kvrocks/src/compact_filter.cc:111 (unittest+0x18605c)
    #4 rocksdb::CompactionFilter::FilterV2(int, rocksdb::Slice const&, rocksdb::CompactionFilter::ValueType, rocksdb::Slice const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >*) const /home/runner/work/incubator-kvrocks/incubator-kvrocks/build/_deps/rocksdb-src/include/rocksdb/compaction_filter.h:171 (unittest+0x67ba24)
    #5 rocksdb::CompactionIterator::InvokeFilterIfNeeded(bool*, rocksdb::Slice*) /home/runner/work/incubator-kvrocks/incubator-kvrocks/build/_deps/rocksdb-src/db/compaction/compaction_iterator.cc:276 (unittest+0x67ba24)
  Previous write of size 1 at 0x7b7c0000673b by main thread (mutexes: write M19766):
    #0 memcpy <null> (libtsan.so.0+0x61afe)
    #1 memcpy /usr/include/x86_64-linux-gnu/bits/string_fortified.h:34 (unittest+0x427deb)
    #2 rocksdb::MemTable::Add(unsigned long, rocksdb::ValueType, rocksdb::Slice const&, rocksdb::Slice const&, rocksdb::ProtectionInfoKVOS<unsigned long> const*, bool, rocksdb::MemTablePostProcessInfo*, void**) /home/runner/work/incubator-kvrocks/incubator-kvrocks/build/_deps/rocksdb-src/db/memtable.cc:556 (unittest+0x427deb)
    #3 Redis::Bitmap::SetBit(rocksdb::Slice const&, unsigned int, bool, bool*) /home/runner/work/incubator-kvrocks/incubator-kvrocks/src/redis_bitmap.cc:217 (unittest+0x1b727e)
    #4 RedisBitmapTest_BitPosSetBit_Test::TestBody() /home/runner/work/incubator-kvrocks/incubator-kvrocks/tests/t_bitmap_test.cc:86 (unittest+0xedaa1)
    #5 void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/runner/work/incubator-kvrocks/incubator-kvrocks/build/_deps/gtest-src/googletest/src/gtest.cc:2607 (unittest+0x7ee349)
    #6 void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/runner/work/incubator-kvrocks/incubator-kvrocks/build/_deps/gtest-src/googletest/src/gtest.cc:2643 (unittest+0x7ee349)
    #7 __libc_start_main <null> (libc.so.6+0x21c86)
  Location is heap block of size 3264 at 0x7b7c00006200 allocated by main thread:
    #0 operator new(unsigned long) <null> (libtsan.so.0+0x8e62e)
    #1 rocksdb::ColumnFamilyData::ConstructNewMemtable(rocksdb::MutableCFOptions const&, unsigned long) /home/runner/work/incubator-kvrocks/incubator-kvrocks/build/_deps/rocksdb-src/db/column_family.cc:1065 (unittest+0x66cc9d)
    #2 Engine::Storage::Open() /home/runner/work/incubator-kvrocks/incubator-kvrocks/src/storage.cc:323 (unittest+0x306775)
    #3 TestBase::TestBase() /home/runner/work/incubator-kvrocks/incubator-kvrocks/tests/test_base.h:34 (unittest+0xef3c8)
    #4 RedisBitmapTest::RedisBitmapTest() /home/runner/work/incubator-kvrocks/incubator-kvrocks/tests/t_bitmap_test.cc:28 (unittest+0xef3c8)
    #5 RedisBitmapTest_BitPosSetBit_Test::RedisBitmapTest_BitPosSetBit_Test() /home/runner/work/incubator-kvrocks/incubator-kvrocks/tests/t_bitmap_test.cc:82 (unittest+0xef3c8)
    #6 testing::internal::TestFactoryImpl<RedisBitmapTest_BitPosSetBit_Test>::CreateTest() /home/runner/work/incubator-kvrocks/incubator-kvrocks/build/_deps/gtest-src/googletest/include/gtest/internal/gtest-internal.h:472 (unittest+0xef3c8)
    #7 testing::Test* testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::TestFactoryBase, testing::Test*>(testing::internal::TestFactoryBase*, testing::Test* (testing::internal::TestFactoryBase::*)(), char const*) /home/runner/work/incubator-kvrocks/incubator-kvrocks/build/_deps/gtest-src/googletest/src/gtest.cc:2607 (unittest+0x7ee4f9)
    #8 testing::Test* testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::TestFactoryBase, testing::Test*>(testing::internal::TestFactoryBase*, testing::Test* (testing::internal::TestFactoryBase::*)(), char const*) /home/runner/work/incubator-kvrocks/incubator-kvrocks/build/_deps/gtest-src/googletest/src/gtest.cc:2643 (unittest+0x7ee4f9)
    #9 __libc_start_main <null> (libc.so.6+0x21c86)
  Mutex M19766 (0x7b0c000cbc70) created at:
    #0 pthread_mutex_lock <null> (libtsan.so.0+0x532b4)
    #1 __gthread_mutex_lock /usr/include/x86_64-linux-gnu/c++/7/bits/gthr-default.h:748 (unittest+0x1ada7e)
    #2 std::mutex::lock() /usr/include/c++/7/bits/std_mutex.h:103 (unittest+0x1ada7e)
    #3 LockManager::Lock(rocksdb::Slice const&) /home/runner/work/incubator-kvrocks/incubator-kvrocks/src/lock_manager.cc:49 (unittest+0x1ada7e)
    #4 LockGuard::LockGuard(LockManager*, rocksdb::Slice) /home/runner/work/incubator-kvrocks/incubator-kvrocks/src/lock_manager.h:52 (unittest+0x1b698f)
    #5 Redis::Bitmap::SetBit(rocksdb::Slice const&, unsigned int, bool, bool*) /home/runner/work/incubator-kvrocks/incubator-kvrocks/src/redis_bitmap.cc:[169](https://github.com/apache/incubator-kvrocks/runs/6922999327?check_suite_focus=true#step:7:170) (unittest+0x1b698f)
    #6 RedisBitmapTest_BitPosSetBit_Test::TestBody() /home/runner/work/incubator-kvrocks/incubator-kvrocks/tests/t_bitmap_test.cc:86 (unittest+0xedaa1)
    #7 void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/runner/work/incubator-kvrocks/incubator-kvrocks/build/_deps/gtest-src/googletest/src/gtest.cc:2607 (unittest+0x7ee349)
    #8 void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/runner/work/incubator-kvrocks/incubator-kvrocks/build/_deps/gtest-src/googletest/src/gtest.cc:2643 (unittest+0x7ee349)
    #9 __libc_start_main <null> (libc.so.6+0x21c86)
  Thread T1 'rocksdb:low' (tid=14682, running) created by main thread at:
    #0 pthread_create <null> (libtsan.so.0+0x5fe84)
    #1 std::thread::_M_start_thread(std::unique_ptr<std::thread::_State, std::default_delete<std::thread::_State> >, void (*)()) <null> (unittest+0x83c9d4)
    #2 Engine::Storage::Open(bool) /home/runner/work/incubator-kvrocks/incubator-kvrocks/src/storage.cc:238 (unittest+0x304953)
    #3 Engine::Storage::Open() /home/runner/work/incubator-kvrocks/incubator-kvrocks/src/storage.cc:323 (unittest+0x306775)
    #4 Compact_Filter_Test::TestBody() /home/runner/work/incubator-kvrocks/incubator-kvrocks/tests/compact_test.cc:36 (unittest+0xc57be)
    #5 void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/runner/work/incubator-kvrocks/incubator-kvrocks/build/_deps/gtest-src/googletest/src/gtest.cc:2607 (unittest+0x7ee349)
    #6 void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/runner/work/incubator-kvrocks/incubator-kvrocks/build/_deps/gtest-src/googletest/src/gtest.cc:2643 (unittest+0x7ee349)
    #7 __libc_start_main <null> (libc.so.6+0x21c86)
SUMMARY: ThreadSanitizer: data race (/usr/lib/x86_64-linux-gnu/libtsan.so.0+0x67cb3) in memcmp

For more details check https://github.com/apache/incubator-kvrocks/runs/6922999327 or reproduce in your side.

Anything Else?

As in #630 (comment), we create an issue for this bug to reference easily.

Are you willing to submit a PR?

• I'm willing to submit a PR!

[git-hulk]

I think maybe it's a false leak report. Coz the main thread will write the memtable
and convert the memtable to immutable state after it reached the max limit, then RocksDB background will read the memtable and flush them into disk. So it should be expected behavior that have the data race between main thread and background thread, but will not cause problem.

HDYT? @ShooterIT @PragmaTwice @tisonkun

[PragmaTwice]

I think maybe it's a false leak report. Coz the main thread will write the memtable and convert the memtable to immutable state after it reached the max limit, then RocksDB background will read the memtable and flush them into disk. So it should be expected behavior that have the data race between main thread and background thread, but will not cause problem.

HDYT? @ShooterIT @PragmaTwice @tisonkun

Seems the writing in kvrocks main thread and the reading in rocksdb background thread occurs at the same time and in the same memory location? Won't this be a problem?

[git-hulk]

Yes, background thread will read the immutable memory table only which the main thread won't write after it become immutable.

[mapleFU]

RocksDB will only have one "writeable" memtable, on default, it will be a lock-free skiplist. And when it's full, it will be "frozen" and only readable. Frozen memtable will only be read by user or compaction, it will never be modified.

I think the case strange, the memory is created by ConstructNewMemtable, modified by rocksdb::MemTable::Add, and detect a race when CompactionFilter is called. And an "writable" memtable will not be compacted.

Maybe TSAN thinks Memtable is protected by LockGuard, but only write is guarded by it, and the following read didn't call LockGuard.

I'm not familiar with TSAN, maybe I made some mistakes. @PragmaTwice

[PragmaTwice]

I may know the root cause of this problem, it may be a false positive due to the rocksdb library not being instrumented by TSan.

Did not notice this when I refactor cmake files. I will fix it later. 😢

[PragmaTwice]

Solved by #759.

[git-hulk]

Thanks for @PragmaTwice great help, we finally got the TSAN and ASAN in CI.