Major Description
I saw this on a local branch but I don't think I changed the logic. Since we have suspicions about the safety of some usages of the RpcRetrier, I thought I'd file this in case it's a latent race in the committed code.
=================================================================
==18338==ERROR: AddressSanitizer: heap-use-after-free on address 0x60f00003e5d0 at pc 0x2284dd7 bp 0x7f288d508fd0 sp 0x7f288d508fc8
READ of size 8 at 0x60f00003e5d0 thread T688 (rpc reactor-214)
I1211 01:38:33.401448 21548 tablet_bootstrap.cc:452] Will attempt to recover log segment: /tmp/kudutest-1000/master_replication-itest.MasterReplicationTest.TestSysTablesReplication.1418290705580984-18338/minicluster-data/ts-2-root/wals/c14eeba03d934ef8a2e54045eb1b1f29/wal-000000001 to: /tmp/kudutest-1000/master_replication-itest.MasterReplicationTest.TestSysTablesReplication.1418290705580984-18338/minicluster-data/ts-2-root/wals/c14eeba03d934ef8a2e54045eb1b1f29.recovery/wal-000000001
I1211 01:38:33.401643 21548 tablet_bootstrap.cc:462] Moved log directory: /tmp/kudutest-1000/master_replication-itest.MasterReplicationTest.TestSysTablesReplication.1418290705580984-18338/minicluster-data/ts-2-root/wals/c14eeba03d934ef8a2e54045eb1b1f29 to recovery directory: /tmp/kudutest-1000/master_replication-itest.MasterReplicationTest.TestSysTablesReplication.1418290705580984-18338/minicluster-data/ts-2-root/wals/c14eeba03d934ef8a2e54045eb1b1f29.recovery
#0 0x2284dd6 in kudu::MonoTime::Initialized() const /home/mpercy/src/kudu/src/kudu/util/monotime.cc:175
#1 0x207db0e in kudu::rpc::RpcRetrier::DelayedRetryCb(kudu::rpc::Rpc*, kudu::Status const&) /home/mpercy/src/kudu/src/kudu/rpc/rpc.cc:57
#2 0x207f6aa in void boost::_bi::bind_t<void, boost::_mfi::mf2<void, kudu::rpc::RpcRetrier, kudu::rpc::Rpc*, kudu::Status const&>, boost::_bi::list3<boost::_bi::value<kudu::rpc::RpcRetrier*>, boost::_bi::value<kudu::rpc::Rpc*>, boost::arg<1> > >::operator()<kudu::Status>(kudu::Status const&) /usr/include/boost/bind/bind_template.hpp:47
#3 0x1256cd6 in boost::function1<void, kudu::Status const&>::operator()(kudu::Status const&) const /usr/include/boost/function/function_template.hpp:766
#4 0x2062eb0 in kudu::rpc::DelayedTask::TimerHandler(ev::timer&, int) /home/mpercy/src/kudu/src/kudu/rpc/reactor.cc:468
#5 0x20fbe94 in ev_invoke_pending /home/mpercy/src/kudu/thirdparty/libev-4.15/ev.c:2994
#6 0x20ff0d4 in ev_run /home/mpercy/src/kudu/thirdparty/libev-4.15/ev.c:3394
#7 0x205a974 in kudu::rpc::ReactorThread::RunThread() /home/mpercy/src/kudu/src/kudu/rpc/reactor.cc:294
#8 0x207a623 in boost::_bi::bind_t<void, boost::_mfi::mf0<void, kudu::rpc::ReactorThread>, boost::_bi::list1<boost::_bi::value<kudu::rpc::ReactorThread*> > >::operator()() /usr/include/boost/bind/bind_template.hpp:20
#9 0x1256f17 in boost::function0<void>::operator()() const /usr/include/boost/function/function_template.hpp:766
#10 0x22bcb25 in kudu::Thread::SuperviseThread(void*) /home/mpercy/src/kudu/src/kudu/util/thread.cc:436
#11 0x7f28fbf97181 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x8181)
#0 0x7f28fac43efc in clone /build/buildd/eglibc-2.19/misc/../sysdeps/unix/sysv/linux/x86_64/clone.S:111
0x60f00003e5d0 is located 16 bytes inside of 168-byte region [0x60f00003e5c0,0x60f00003e668)
freed by thread T688 (rpc reactor-214) here:
#0 0xf3052e in operator delete(void*) /home/mpercy/src/kudu/thirdparty/llvm-3.4.2.src/projects/compiler-rt/lib/asan/asan_new_delete.cc:83
#1 0x1fb99c4 in kudu::internal::BindState<kudu::internal::RunnableAdapter<void (kudu::master::GetLeaderMasterRpc::*)(kudu::ServerEntryPB const&, kudu::Status const&)>, void (kudu::master::GetLeaderMasterRpc*, kudu::ServerEntryPB const&, kudu::Status const&), void (kudu::master::GetLeaderMasterRpc*, kudu::ServerEntryPB)>::~BindState() /home/mpercy/src/kudu/src/kudu/gutil/bind_internal.h:2493
#2 0x1fb9a82 in kudu::internal::BindState<kudu::internal::RunnableAdapter<void (kudu::master::GetLeaderMasterRpc::*)(kudu::ServerEntryPB const&, kudu::Status const&)>, void (kudu::master::GetLeaderMasterRpc*, kudu::ServerEntryPB const&, kudu::Status const&), void (kudu::master::GetLeaderMasterRpc*, kudu::ServerEntryPB)>::~BindState() /home/mpercy/src/kudu/src/kudu/gutil/bind_internal.h:2493
#3 0x1fb5ae5 in kudu::master::GetMasterRegistrationRpc::~GetMasterRegistrationRpc() /home/mpercy/src/kudu/src/kudu/master/master_rpc.cc:47
#4 0x1fb5a62 in kudu::master::GetMasterRegistrationRpc::~GetMasterRegistrationRpc() /home/mpercy/src/kudu/src/kudu/master/master_rpc.cc:46
#5 0x1fb64db in kudu::master::GetMasterRegistrationRpc::SendRpcCb(kudu::Status const&) /home/mpercy/src/kudu/src/kudu/master/master_rpc.cc:83
#6 0x1fbc093 in boost::_bi::bind_t<void, boost::_mfi::mf1<void, kudu::master::GetMasterRegistrationRpc, kudu::Status const&>, boost::_bi::list2<boost::_bi::value<kudu::master::GetMasterRegistrationRpc*>, boost::_bi::value<kudu::Status> > >::operator()() /usr/include/boost/bind/bind_template.hpp:20
#7 0x1256f17 in boost::function0<void>::operator()() const /usr/include/boost/function/function_template.hpp:766
#8 0x2041835 in kudu::rpc::OutboundCall::CallCallback() /home/mpercy/src/kudu/src/kudu/rpc/outbound_call.cc:141
#9 0x2041ad4 in kudu::rpc::OutboundCall::SetResponse(gscoped_ptr<kudu::rpc::CallResponse, kudu::DefaultDeleter<kudu::rpc::CallResponse> >) /home/mpercy/src/kudu/src/kudu/rpc/outbound_call.cc:161
#10 0x2099e03 in kudu::rpc::Connection::HandleCallResponse(gscoped_ptr<kudu::rpc::InboundTransfer, kudu::DefaultDeleter<kudu::rpc::InboundTransfer> >) /home/mpercy/src/kudu/src/kudu/rpc/connection.cc:459
#11 0x2099129 in kudu::rpc::Connection::ReadHandler(ev::io&, int) /home/mpercy/src/kudu/src/kudu/rpc/connection.cc:395
#12 0x20fbe94 in ev_invoke_pending /home/mpercy/src/kudu/thirdparty/libev-4.15/ev.c:2994
previously allocated by thread T728 (heartbeat-21539) here:
#0 0xf3022e in operator new(unsigned long) /home/mpercy/src/kudu/thirdparty/llvm-3.4.2.src/projects/compiler-rt/lib/asan/asan_new_delete.cc:52
#1 0x1113cda in kudu::tserver::Heartbeater::Thread::FindLeaderMaster(kudu::MonoTime const&, kudu::HostPort*) /home/mpercy/src/kudu/src/kudu/tserver/heartbeater.cc:190
#2 0x11144a1 in kudu::tserver::Heartbeater::Thread::ConnectToMaster() /home/mpercy/src/kudu/src/kudu/tserver/heartbeater.cc:204
#3 0x11165d1 in kudu::tserver::Heartbeater::Thread::DoHeartbeat() /home/mpercy/src/kudu/src/kudu/tserver/heartbeater.cc:294
#4 0x1117802 in kudu::tserver::Heartbeater::Thread::RunThread() /home/mpercy/src/kudu/src/kudu/tserver/heartbeater.cc:363
#5 0x111ba83 in boost::_bi::bind_t<void, boost::_mfi::mf0<void, kudu::tserver::Heartbeater::Thread>, boost::_bi::list1<boost::_bi::value<kudu::tserver::Heartbeater::Thread*> > >::operator()() /usr/include/boost/bind/bind_template.hpp:20
#6 0x1256f17 in boost::function0<void>::operator()() const /usr/include/boost/function/function_template.hpp:766
#7 0x22bcb25 in kudu::Thread::SuperviseThread(void*) /home/mpercy/src/kudu/src/kudu/util/thread.cc:436
#8 0x7f28fbf97181 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x8181)
Thread T688 (rpc reactor-214) created by T0 here:
#0 0xf1ef62 in __interceptor_pthread_create /home/mpercy/src/kudu/thirdparty/llvm-3.4.2.src/projects/compiler-rt/lib/asan/asan_interceptors.cc:185
#1 0x22bc137 in kudu::Thread::StartThread(std::string const&, std::string const&, boost::function<void ()> const&, scoped_refptr<kudu::Thread>*) /home/mpercy/src/kudu/src/kudu/util/thread.cc:366
#2 0x2065b52 in kudu::Status kudu::Thread::Create<void (kudu::rpc::ReactorThread::*)(), kudu::rpc::ReactorThread*>(std::string const&, std::string const&, void (kudu::rpc::ReactorThread::* const&)(), kudu::rpc::ReactorThread* const&, scoped_refptr<kudu::Thread>*) /home/mpercy/src/kudu/src/kudu/util/thread.h:123
#3 0x205a52c in kudu::rpc::ReactorThread::Init() /home/mpercy/src/kudu/src/kudu/rpc/reactor.cc:81
#4 0x20635fa in kudu::rpc::Reactor::Init() /home/mpercy/src/kudu/src/kudu/rpc/reactor.cc:483
#5 0x204831b in kudu::rpc::Messenger::Init() /home/mpercy/src/kudu/src/kudu/rpc/messenger.cc:237
#6 0x2047e50 in kudu::rpc::MessengerBuilder::Build(kudu::rpc::Messenger**) /home/mpercy/src/kudu/src/kudu/rpc/messenger.cc:83
#7 0x2048684 in kudu::rpc::MessengerBuilder::Build(std::tr1::shared_ptr<kudu::rpc::Messenger>*) /home/mpercy/src/kudu/src/kudu/rpc/messenger.cc:90
#8 0x1165e83 in kudu::server::ServerBase::Init() /home/mpercy/src/kudu/src/kudu/server/server_base.cc:119
#9 0x10ad263 in kudu::tserver::TabletServer::Init() /home/mpercy/src/kudu/src/kudu/tserver/tablet_server.cc:76
#10 0x10a9893 in kudu::tserver::MiniTabletServer::Start() /home/mpercy/src/kudu/src/kudu/tserver/mini_tablet_server.cc:56
#11 0xf67da3 in kudu::MiniCluster::AddTabletServer() /home/mpercy/src/kudu/src/kudu/integration-tests/mini_cluster.cc:187
#12 0xf64b8b in kudu::MiniCluster::Start() /home/mpercy/src/kudu/src/kudu/integration-tests/mini_cluster.cc:78
#13 0xf4c6b6 in kudu::master::MasterReplicationTest::RestartCluster() /home/mpercy/src/kudu/src/kudu/integration-tests/master_replication-itest.cc:66
#14 0xf467c0 in kudu::master::MasterReplicationTest_TestSysTablesReplication_Test::TestBody() /home/mpercy/src/kudu/src/kudu/integration-tests/master_replication-itest.cc:205
#15 0x21ef6f2 in HandleSehExceptionsInMethodIfSupported<testing::Test, void> /home/mpercy/src/kudu/thirdparty/gmock-1.7.0/gtest/src/gtest.cc:2078
#16 0x21ef6f2 in void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/mpercy/src/kudu/thirdparty/gmock-1.7.0/gtest/src/gtest.cc:2114
Thread T728 (heartbeat-21539) created by T0 here:
#0 0xf1ef62 in __interceptor_pthread_create /home/mpercy/src/kudu/thirdparty/llvm-3.4.2.src/projects/compiler-rt/lib/asan/asan_interceptors.cc:185
#1 0x22bc137 in kudu::Thread::StartThread(std::string const&, std::string const&, boost::function<void ()> const&, scoped_refptr<kudu::Thread>*) /home/mpercy/src/kudu/src/kudu/util/thread.cc:366
#2 0x111a8d2 in kudu::Status kudu::Thread::Create<void (kudu::tserver::Heartbeater::Thread::*)(), kudu::tserver::Heartbeater::Thread*>(std::string const&, std::string const&, void (kudu::tserver::Heartbeater::Thread::* const&)(), kudu::tserver::Heartbeater::Thread* const&, scoped_refptr<kudu::Thread>*) /home/mpercy/src/kudu/src/kudu/util/thread.h:123
#3 0x1112c61 in kudu::tserver::Heartbeater::Thread::Start() /home/mpercy/src/kudu/src/kudu/tserver/heartbeater.cc:389
#4 0x1112a38 in kudu::tserver::Heartbeater::Start() /home/mpercy/src/kudu/src/kudu/tserver/heartbeater.cc:145
#5 0x10adc37 in kudu::tserver::TabletServer::Start() /home/mpercy/src/kudu/src/kudu/tserver/tablet_server.cc:108
#6 0x10a98ce in kudu::tserver::MiniTabletServer::Start() /home/mpercy/src/kudu/src/kudu/tserver/mini_tablet_server.cc:57
#7 0xf67da3 in kudu::MiniCluster::AddTabletServer() /home/mpercy/src/kudu/src/kudu/integration-tests/mini_cluster.cc:187
#8 0xf64b8b in kudu::MiniCluster::Start() /home/mpercy/src/kudu/src/kudu/integration-tests/mini_cluster.cc:78
#9 0xf4c6b6 in kudu::master::MasterReplicationTest::RestartCluster() /home/mpercy/src/kudu/src/kudu/integration-tests/master_replication-itest.cc:66
#10 0xf467c0 in kudu::master::MasterReplicationTest_TestSysTablesReplication_Test::TestBody() /home/mpercy/src/kudu/src/kudu/integration-tests/master_replication-itest.cc:205
#11 0x21ef6f2 in HandleSehExceptionsInMethodIfSupported<testing::Test, void> /home/mpercy/src/kudu/thirdparty/gmock-1.7.0/gtest/src/gtest.cc:2078
#12 0x21ef6f2 in void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/mpercy/src/kudu/thirdparty/gmock-1.7.0/gtest/src/gtest.cc:2114
SUMMARY: AddressSanitizer: heap-use-after-free /home/mpercy/src/kudu/src/kudu/util/monotime.cc:175 kudu::MonoTime::Initialized() const
Shadow bytes around the buggy address:
0x0c1e7ffffc60: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c1e7ffffc70: fd fd fd fa fa fa fa fa fa fa fa fa fd fd fd fd
0x0c1e7ffffc80: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c1e7ffffc90: fd fa fa fa fa fa fa fa fa fa fd fd fd fd fd fd
0x0c1e7ffffca0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fa
=>0x0c1e7ffffcb0: fa fa fa fa fa fa fa fa fd fd[fd]fd fd fd fd fd
0x0c1e7ffffcc0: fd fd fd fd fd fd fd fd fd fd fd fd fd fa fa fa
0x0c1e7ffffcd0: fa fa fa fa fa fa fd fd fd fd fd fd fd fd fd fd
0x0c1e7ffffce0: fd fd fd fd fd fd fd fd fd fd fd fa fa fa fa fa
0x0c1e7ffffcf0: fa fa fa fa fd fd fd fd fd fd fd fd fd fd fd fd
0x0c1e7ffffd00: fd fd fd fd fd fd fd fd fd fa fa fa fa fa fa fa
Shadow byte legend (one shadow byte represents 8 application bytes):
Addressable: 00
Partially addressable: 01 02 03 04 05 06 07
Heap left redzone: fa
Heap right redzone: fb
Freed heap region: fd
Stack left redzone: f1
Stack mid redzone: f2
Stack right redzone: f3
Stack partial redzone: f4
Stack after return: f5
Stack use after scope: f8
Global redzone: f9
Global init order: f6
Poisoned by user: f7
ASan internal: fe
==18338==ABORTING