bazel tsan failure when running grpc test

[AspirinSJL]

Hi, we are seeing a data race in our test grpc/grpc#17175. And it seems an issue in absl.

Below is the tsan log.

It's a conflict between the memset to the whole ThreadIdentity in NewThreadIdentity() and the write to the Waiter's futex_ member. The Waiter is a member of ThreadIdentity.

Actually, the ThreadIdentity was just reused from the freelist or allocated from scratch. It's more likely that this race happens when we reuse an instance from the freelist, but the instance in freelist somehow is still active.

Any idea? Thanks!

[ RUN      ] StatsPluginEnd2EndTest.RequestReceivedMessagesPerRpc
I1109 20:30:28.414991659      18 ev_epoll1_linux.cc:116]     grpc epoll fd: 3
D1109 20:30:28.415069617      18 ev_posix.cc:169]            Using polling engine: epoll1
D1109 20:30:28.415237246      18 dns_resolver.cc:338]        Using native dns resolver
I1109 20:30:28.416057711      18 server_builder.cc:280]      Synchronous server. Num CQs: 1, Min pollers: 1, Max Pollers: 2, CQ timeout (msec): 10000
D1109 20:30:28.423923579      18 dns_resolver.cc:279]        Start resolving.
I1109 20:30:28.426770518      49 subchannel.cc:841]          New connected subchannel at 0x7b0c00001e90 for subchannel 0x7b5400010b80
==================
WARNING: ThreadSanitizer: data race (pid=18)
  Atomic write of size 4 at 0x7f09bd014350 by main thread:
    #0 __tsan_atomic32_fetch_add /tmp/clang-build/src/compiler-rt/lib/tsan/rtl/tsan_interface_atomic.cc:616 (grpc_opencensus_plugin_test+0x519510)
    #1 fetch_add /usr/lib/gcc/x86_64-linux-gnu/4.9/../../../../include/c++/4.9/bits/atomic_base.h:618 (libexternal_Scom_Ugoogle_Uabsl_Sabsl_Ssynchronization_Slibsynchronization.so+0xb424)
    #2 Post /proc/self/cwd/external/com_google_absl/absl/synchronization/internal/waiter.cc:155 (libexternal_Scom_Ugoogle_Uabsl_Sabsl_Ssynchronization_Slibsynchronization.so+0xb424)
    #3 AbslInternalPerThreadSemPost /proc/self/cwd/external/com_google_absl/absl/synchronization/internal/per_thread_sem.cc:67 (libexternal_Scom_Ugoogle_Uabsl_Sabsl_Ssynchronization_Slibsynchronization.so+0x9c10)
    #4 absl::synchronization_internal::PerThreadSem::Post(absl::base_internal::ThreadIdentity*) /proc/self/cwd/external/com_google_absl/absl/synchronization/internal/per_thread_sem.h:100 (libexternal_Scom_Ugoogle_Uabsl_Sabsl_Ssynchronization_Slibsynchronization.so+0x2b398)
    #5 absl::Mutex::IncrementSynchSem(absl::Mutex*, absl::base_internal::PerThreadSynch*) /proc/self/cwd/external/com_google_absl/absl/synchronization/mutex.cc:531 (libexternal_Scom_Ugoogle_Uabsl_Sabsl_Ssynchronization_Slibsynchronization.so+0x2a6dc)
    #6 absl::Mutex::Wakeup(absl::base_internal::PerThreadSynch*) /proc/self/cwd/external/com_google_absl/absl/synchronization/mutex.cc:1118 (libexternal_Scom_Ugoogle_Uabsl_Sabsl_Ssynchronization_Slibsynchronization.so+0xee3d)
    #7 absl::Mutex::UnlockSlow(absl::SynchWaitParams*) /proc/self/cwd/external/com_google_absl/absl/synchronization/mutex.cc:2267 (libexternal_Scom_Ugoogle_Uabsl_Sabsl_Ssynchronization_Slibsynchronization.so+0x1734e)
    #8 absl::Mutex::Unlock() /proc/self/cwd/external/com_google_absl/absl/synchronization/mutex.cc:1674 (libexternal_Scom_Ugoogle_Uabsl_Sabsl_Ssynchronization_Slibsynchronization.so+0x1ec17)
    #9 absl::MutexLock::~MutexLock() /proc/self/cwd/external/com_google_absl/absl/synchronization/mutex.h:528 (libexternal_Sio_Uopencensus_Ucpp_Sopencensus_Strace_Slibtrace.so+0x69d28)
    #10 opencensus::stats::DeltaProducer::Record(std::initializer_list<opencensus::stats::Measurement>, opencensus::stats::TagSet) /proc/self/cwd/external/io_opencensus_cpp/opencensus/stats/internal/delta_producer.cc:107 (libexternal_Sio_Uopencensus_Ucpp_Sopencensus_Sstats_Slibcore.so+0x86970)
    #11 opencensus::stats::Record(std::initializer_list<opencensus::stats::Measurement>, opencensus::stats::TagSet) /proc/self/cwd/external/io_opencensus_cpp/opencensus/stats/internal/recording.cc:26 (libexternal_Sio_Uopencensus_Ucpp_Sopencensus_Sstats_Slibrecording.so+0x1db9)
    #12 grpc::CensusClientCallData::Destroy(grpc_call_element*, grpc_call_final_info const*, grpc_closure*) /proc/self/cwd/src/cpp/ext/filters/census/client_filter.cc:151 (liblibgrpc_Uopencensus_Uplugin.so+0x14a41)
    #13 grpc::internal::ChannelFilter<grpc::CensusChannelData, grpc::CensusClientCallData>::DestroyCallElement(grpc_call_element*, grpc_call_final_info const*, grpc_closure*) /proc/self/cwd/./src/cpp/common/channel_filter.h:333 (liblibgrpc_Uopencensus_Uplugin.so+0x1bf7d)
    #14 grpc_call_stack_destroy(grpc_call_stack*, grpc_call_final_info const*, grpc_closure*) /proc/self/cwd/src/core/lib/channel/channel_stack.cc:217 (liblibgrpc_Ubase_Uc.so+0x3d23c)
    #15 destroy_call(void*, grpc_error*) /proc/self/cwd/src/core/lib/surface/call.cc:546 (liblibgrpc_Ubase_Uc.so+0xda4c4)
    #16 exec_ctx_run(grpc_closure*, grpc_error*) /proc/self/cwd/src/core/lib/iomgr/exec_ctx.cc:40 (liblibgrpc_Ubase_Uc.so+0x89e6b)
    #17 grpc_core::ExecCtx::Flush() /proc/self/cwd/src/core/lib/iomgr/exec_ctx.cc:134 (liblibgrpc_Ubase_Uc.so+0x89bb3)
    #18 grpc_core::ExecCtx::~ExecCtx() /proc/self/cwd/./src/core/lib/iomgr/exec_ctx.h:108 (liblibgrpc++_Ubase.so+0xdced9)
    #19 grpc_call_unref /proc/self/cwd/src/core/lib/surface/call.cc:595 (liblibgrpc_Ubase_Uc.so+0xdb137)
    #20 grpc::ClientContext::~ClientContext() /proc/self/cwd/src/cpp/client/client_context.cc:65 (liblibgrpc++_Ubase.so+0xbf572)
    #21 grpc::testing::(anonymous namespace)::StatsPluginEnd2EndTest_RequestReceivedMessagesPerRpc_Test::TestBody() /proc/self/cwd/test/cpp/ext/filters/census/stats_plugin_end2end_test.cc:333 (grpc_opencensus_plugin_test+0x546d2f)
    #22 void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /proc/self/cwd/external/com_github_google_googletest/googletest/src/gtest.cc:2402 (grpc_opencensus_plugin_test+0x652f86)
    #23 void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /proc/self/cwd/external/com_github_google_googletest/googletest/src/gtest.cc:2438 (grpc_opencensus_plugin_test+0x6309e2)
    #24 testing::Test::Run() /proc/self/cwd/external/com_github_google_googletest/googletest/src/gtest.cc:2474 (grpc_opencensus_plugin_test+0x60c05e)
    #25 testing::TestInfo::Run() /proc/self/cwd/external/com_github_google_googletest/googletest/src/gtest.cc:2656 (grpc_opencensus_plugin_test+0x60d206)
    #26 testing::TestCase::Run() /proc/self/cwd/external/com_github_google_googletest/googletest/src/gtest.cc:2774 (grpc_opencensus_plugin_test+0x60dc37)
    #27 testing::internal::UnitTestImpl::RunAllTests() /proc/self/cwd/external/com_github_google_googletest/googletest/src/gtest.cc:4649 (grpc_opencensus_plugin_test+0x618cbf)
    #28 bool testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /proc/self/cwd/external/com_github_google_googletest/googletest/src/gtest.cc:2402 (grpc_opencensus_plugin_test+0x6597b6)
    #29 bool testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /proc/self/cwd/external/com_github_google_googletest/googletest/src/gtest.cc:2438 (grpc_opencensus_plugin_test+0x6347c8)
    #30 testing::UnitTest::Run() /proc/self/cwd/external/com_github_google_googletest/googletest/src/gtest.cc:4257 (grpc_opencensus_plugin_test+0x61872b)
    #31 RUN_ALL_TESTS() /proc/self/cwd/external/com_github_google_googletest/googletest/include/gtest/gtest.h:2233 (grpc_opencensus_plugin_test+0x548ae7)
    #32 main /proc/self/cwd/test/cpp/ext/filters/census/stats_plugin_end2end_test.cc:375 (grpc_opencensus_plugin_test+0x53a260)
  Previous write of size 8 at 0x7f09bd014350 by thread T15:
    #0 memset /tmp/clang-build/src/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:764 (grpc_opencensus_plugin_test+0x4dabc9)
    #1 absl::synchronization_internal::NewThreadIdentity() /proc/self/cwd/external/com_google_absl/absl/synchronization/internal/create_thread_identity.cc:93 (libexternal_Scom_Ugoogle_Uabsl_Sabsl_Ssynchronization_Slibsynchronization.so+0x8695)
    #2 absl::synchronization_internal::CreateThreadIdentity() /proc/self/cwd/external/com_google_absl/absl/synchronization/internal/create_thread_identity.cc:102 (libexternal_Scom_Ugoogle_Uabsl_Sabsl_Ssynchronization_Slibsynchronization.so+0x8535)
    #3 absl::synchronization_internal::GetOrCreateCurrentThreadIdentity() /proc/self/cwd/external/com_google_absl/absl/synchronization/internal/create_thread_identity.h:46 (libexternal_Scom_Ugoogle_Uabsl_Sabsl_Ssynchronization_Slibsynchronization.so+0xa376)
    #4 absl::Synch_GetPerThread() /proc/self/cwd/external/com_google_absl/absl/synchronization/mutex.cc:503 (libexternal_Scom_Ugoogle_Uabsl_Sabsl_Ssynchronization_Slibsynchronization.so+0x278f5)
    #5 absl::Synch_GetPerThreadAnnotated(absl::Mutex*) /proc/self/cwd/external/com_google_absl/absl/synchronization/mutex.cc:511 (libexternal_Scom_Ugoogle_Uabsl_Sabsl_Ssynchronization_Slibsynchronization.so+0x131f4)
    #6 absl::Mutex::LockSlowWithDeadline(absl::MuHowS const*, absl::Condition const*, absl::synchronization_internal::KernelTimeout, int) /proc/self/cwd/external/com_google_absl/absl/synchronization/mutex.cc:1818 (libexternal_Scom_Ugoogle_Uabsl_Sabsl_Ssynchronization_Slibsynchronization.so+0x12245)
    #7 absl::Mutex::LockSlow(absl::MuHowS const*, absl::Condition const*, int) /proc/self/cwd/external/com_google_absl/absl/synchronization/mutex.cc:1729 (libexternal_Scom_Ugoogle_Uabsl_Sabsl_Ssynchronization_Slibsynchronization.so+0x1087a)
    #8 absl::Mutex::Lock() /proc/self/cwd/external/com_google_absl/absl/synchronization/mutex.cc:1443 (libexternal_Scom_Ugoogle_Uabsl_Sabsl_Ssynchronization_Slibsynchronization.so+0xfd6e)
    #9 absl::MutexLock::MutexLock(absl::Mutex*) /proc/self/cwd/external/com_google_absl/absl/synchronization/mutex.h:520 (libexternal_Sio_Uopencensus_Ucpp_Sopencensus_Strace_Slibtrace.so+0x6995f)
    #10 opencensus::stats::DeltaProducer::Record(std::initializer_list<opencensus::stats::Measurement>, opencensus::stats::TagSet) /proc/self/cwd/external/io_opencensus_cpp/opencensus/stats/internal/delta_producer.cc:105 (libexternal_Sio_Uopencensus_Ucpp_Sopencensus_Sstats_Slibcore.so+0x868ed)
    #11 opencensus::stats::Record(std::initializer_list<opencensus::stats::Measurement>, opencensus::stats::TagSet) /proc/self/cwd/external/io_opencensus_cpp/opencensus/stats/internal/recording.cc:26 (libexternal_Sio_Uopencensus_Ucpp_Sopencensus_Sstats_Slibrecording.so+0x1db9)
    #12 grpc::CensusServerCallData::Destroy(grpc_call_element*, grpc_call_final_info const*, grpc_closure*) /proc/self/cwd/src/cpp/ext/filters/census/server_filter.cc:186 (liblibgrpc_Uopencensus_Uplugin.so+0x2134c)
    #13 grpc::internal::ChannelFilter<grpc::CensusChannelData, grpc::CensusServerCallData>::DestroyCallElement(grpc_call_element*, grpc_call_final_info const*, grpc_closure*) /proc/self/cwd/./src/cpp/common/channel_filter.h:333 (liblibgrpc_Uopencensus_Uplugin.so+0x1e48d)
    #14 grpc_call_stack_destroy(grpc_call_stack*, grpc_call_final_info const*, grpc_closure*) /proc/self/cwd/src/core/lib/channel/channel_stack.cc:217 (liblibgrpc_Ubase_Uc.so+0x3d23c)
    #15 destroy_call(void*, grpc_error*) /proc/self/cwd/src/core/lib/surface/call.cc:546 (liblibgrpc_Ubase_Uc.so+0xda4c4)
    #16 exec_ctx_run(grpc_closure*, grpc_error*) /proc/self/cwd/src/core/lib/iomgr/exec_ctx.cc:40 (liblibgrpc_Ubase_Uc.so+0x89e6b)
    #17 grpc_core::ExecCtx::Flush() /proc/self/cwd/src/core/lib/iomgr/exec_ctx.cc:134 (liblibgrpc_Ubase_Uc.so+0x89bb3)
    #18 grpc_core::ExecCtx::~ExecCtx() /proc/self/cwd/./src/core/lib/iomgr/exec_ctx.h:108 (liblibgrpc++_Ubase.so+0xdced9)
    #19 grpc_call_unref /proc/self/cwd/src/core/lib/surface/call.cc:595 (liblibgrpc_Ubase_Uc.so+0xdb137)
    #20 grpc::ServerContext::CompletionOp::Unref() /proc/self/cwd/src/cpp/server/server_context.cc:156 (liblibgrpc++_Ubase.so+0x13e8fc)
    #21 grpc::ServerContext::Clear() /proc/self/cwd/src/cpp/server/server_context.cc:254 (liblibgrpc++_Ubase.so+0x13f69b)
    #22 grpc::ServerContext::~ServerContext() /proc/self/cwd/src/cpp/server/server_context.cc:247 (liblibgrpc++_Ubase.so+0x13f50c)
    #23 grpc::Server::SyncRequest::CallData::~CallData() /proc/self/cwd/src/cpp/server/server_cc.cc:259 (liblibgrpc++_Ubase.so+0x12fecd)
    #24 grpc::Server::SyncRequest::CallData::ContinueRunAfterInterception() /proc/self/cwd/src/cpp/server/server_cc.cc:315 (liblibgrpc++_Ubase.so+0x12ee4d)
    #25 grpc::Server::SyncRequest::CallData::Run(std::shared_ptr<grpc::Server::GlobalCallbacks> const&, bool) /proc/self/cwd/src/cpp/server/server_cc.cc:288 (liblibgrpc++_Ubase.so+0x12e729)
    #26 grpc::Server::SyncRequestThreadManager::DoWork(void*, bool, bool) /proc/self/cwd/src/cpp/server/server_cc.cc:572 (liblibgrpc++_Ubase.so+0x12ccd4)
    #27 grpc::ThreadManager::MainWorkLoop() /proc/self/cwd/src/cpp/thread_manager/thread_manager.cc:200 (liblibgrpc++_Ubase.so+0x1436c4)
    #28 grpc::ThreadManager::WorkerThread::Run() /proc/self/cwd/src/cpp/thread_manager/thread_manager.cc:42 (liblibgrpc++_Ubase.so+0x1432a8)
    #29 grpc::ThreadManager::WorkerThread::WorkerThread(grpc::ThreadManager*)::$_0::operator()(void*) const /proc/self/cwd/src/cpp/thread_manager/thread_manager.cc:36 (liblibgrpc++_Ubase.so+0x144574)
    #30 grpc::ThreadManager::WorkerThread::WorkerThread(grpc::ThreadManager*)::$_0::__invoke(void*) /proc/self/cwd/src/cpp/thread_manager/thread_manager.cc:36 (liblibgrpc++_Ubase.so+0x144518)
    #31 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*)::{lambda(void*)#1}::operator()(void*) const /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:100 (liblibgpr_Ubase.so+0x10e83)
    #32 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*)::{lambda(void*)#1}::__invoke(void*) /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:74 (liblibgpr_Ubase.so+0x10cb8)
  Thread T15 'grpcpp_sync_ser' (tid=54, running) created by thread T13 at:
    #0 pthread_create /tmp/clang-build/src/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:965 (grpc_opencensus_plugin_test+0x4d1405)
    #1 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*) /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:73 (liblibgpr_Ubase.so+0x10929)
    #2 grpc_core::(anonymous namespace)::ThreadInternalsPosix* grpc_core::New<grpc_core::(anonymous namespace)::ThreadInternalsPosix, char const*&, void (*&)(void*), void*&, bool*>(char const*&, void (*&)(void*), void*&, bool*&&) /proc/self/cwd/./src/core/lib/gprpp/memory.h:52 (liblibgpr_Ubase.so+0x1051a)
    #3 grpc_core::Thread::Thread(char const*, void (*)(void*), void*, bool*) /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:142 (liblibgpr_Ubase.so+0x102e7)
    #4 grpc::ThreadManager::WorkerThread::WorkerThread(grpc::ThreadManager*) /proc/self/cwd/src/cpp/thread_manager/thread_manager.cc:34 (liblibgrpc++_Ubase.so+0x1431bd)
    #5 grpc::ThreadManager::MainWorkLoop() /proc/self/cwd/src/cpp/thread_manager/thread_manager.cc:180 (liblibgrpc++_Ubase.so+0x1435bc)
    #6 grpc::ThreadManager::WorkerThread::Run() /proc/self/cwd/src/cpp/thread_manager/thread_manager.cc:42 (liblibgrpc++_Ubase.so+0x1432a8)
    #7 grpc::ThreadManager::WorkerThread::WorkerThread(grpc::ThreadManager*)::$_0::operator()(void*) const /proc/self/cwd/src/cpp/thread_manager/thread_manager.cc:36 (liblibgrpc++_Ubase.so+0x144574)
    #8 grpc::ThreadManager::WorkerThread::WorkerThread(grpc::ThreadManager*)::$_0::__invoke(void*) /proc/self/cwd/src/cpp/thread_manager/thread_manager.cc:36 (liblibgrpc++_Ubase.so+0x144518)
    #9 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*)::{lambda(void*)#1}::operator()(void*) const /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:100 (liblibgpr_Ubase.so+0x10e83)
    #10 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*)::{lambda(void*)#1}::__invoke(void*) /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:74 (liblibgpr_Ubase.so+0x10cb8)
SUMMARY: ThreadSanitizer: data race /usr/lib/gcc/x86_64-linux-gnu/4.9/../../../../include/c++/4.9/bits/atomic_base.h:618 in fetch_add
==================

[derekmauro]

Known issue, we think this is a false positive. See google/sanitizers#953.

[AspirinSJL]

Thanks for the pointer!