Ceph » RADOS

While hunting a crash in tracker #42026, I ran across this bug when testing with ASAN:

==20840==ERROR: AddressSanitizer: heap-use-after-free on address 0x60b0007debc0 at pc 0x7f3aac813b37 bp 0x7f395063b3e0 sp 0x7f395063b3d0
READ of size 8 at 0x60b0007debc0 thread T27841
    #0 0x7f3aac813b36 in ceph::timer_detail::timer<ceph::time_detail::coarse_mono_clock>::timer_thread() /home/jlayton/git/ceph/src/common/ceph_timer.h:112
    #1 0x7f3aa17eb6f3  (/lib64/libstdc++.so.6+0xd76f3)
    #2 0x7f3aac48c4bf in start_thread (/lib64/libpthread.so.0+0x84bf)
    #3 0x7f3aa14e8552 in __clone (/lib64/libc.so.6+0xfc552)

0x60b0007debc0 is located 0 bytes inside of 112-byte region [0x60b0007debc0,0x60b0007dec30)
freed by thread T301 here:
    #0 0x7f3aacaab0b5 in operator delete(void*, unsigned long) (/lib64/libasan.so.5+0x1110b5)
    #1 0x7f3aac8376cf in ceph::timer_detail::timer<ceph::time_detail::coarse_mono_clock>::cancel_event(unsigned long) /home/jlayton/git/ceph/src/common/ceph_timer.h:273
    #2 0x7f3aac78c6bb in Objecter::shutdown() /home/jlayton/git/ceph/src/osdc/Objecter.cc:515
    #3 0x7f3aac72661f in librados::v14_2_0::RadosClient::shutdown() /home/jlayton/git/ceph/src/librados/RadosClient.cc:375
    #4 0x7f3aac51f2a3 in _rados_shutdown /home/jlayton/git/ceph/src/librados/librados_c.cc:188
    #5 0x55d1a3750bf6 in shutdown_racer_func /home/jlayton/git/ceph/src/test/librados/misc.cc:322
    #6 0x7f3aa17eb6f3  (/lib64/libstdc++.so.6+0xd76f3)

previously allocated by thread T301 here:
    #0 0x7f3aacaa99d7 in operator new(unsigned long) (/lib64/libasan.so.5+0x10f9d7)
    #1 0x7f3aac75e42d in unsigned long ceph::timer_detail::timer<ceph::time_detail::coarse_mono_clock>::add_event<void (Objecter::*)(), Objecter*>(std::chrono::time_point<ceph::time_detail::coarse_mono_clock, std::chrono::duration<unsigned long, std::ratio<1l, 1000000000l> > >, void (Objecter::*&&)(), Objecter*&&) /home/jlayton/git/ceph/src/common/ceph_timer.h:213
    #2 0x7f3aac75e42d in unsigned long ceph::timer_detail::timer<ceph::time_detail::coarse_mono_clock>::add_event<void (Objecter::*)(), Objecter*>(std::chrono::duration<unsigned long, std::ratio<1l, 1000000000l> >, void (Objecter::*&&)(), Objecter*&&) /home/jlayton/git/ceph/src/common/ceph_timer.h:205
    #3 0x7f3aac75e42d in Objecter::start_tick() /home/jlayton/git/ceph/src/osdc/Objecter.cc:2109
    #4 0x7f3aac77581c in Objecter::start(OSDMap const*) /home/jlayton/git/ceph/src/osdc/Objecter.cc:412
    #5 0x7f3aac72af74 in librados::v14_2_0::RadosClient::connect() /home/jlayton/git/ceph/src/librados/RadosClient.cc:318
    #6 0x7f3aac51efc3 in _rados_connect /home/jlayton/git/ceph/src/librados/librados_c.cc:178
    #7 0x55d1a38c6333 in connect_cluster[abi:cxx11](void**) /home/jlayton/git/ceph/src/test/librados/test.cc:156
    #8 0x55d1a3750c5f in shutdown_racer_func /home/jlayton/git/ceph/src/test/librados/misc.cc:321
    #9 0x7f3aa17eb6f3  (/lib64/libstdc++.so.6+0xd76f3)

Thread T27841 created by T301 here:
    #0 0x7f3aac9d4955 in pthread_create (/lib64/libasan.so.5+0x3a955)
    #1 0x7f3aa17eb9b8 in std::thread::_M_start_thread(std::unique_ptr<std::thread::_State, std::default_delete<std::thread::_State> >, void (*)()) (/lib64/libstdc++.so.6+0xd79b8)
    #2 0x7f3aac729869 in librados::v14_2_0::RadosClient::connect() /home/jlayton/git/ceph/src/librados/RadosClient.cc:266
    #3 0x7f3aac51efc3 in _rados_connect /home/jlayton/git/ceph/src/librados/librados_c.cc:178
    #4 0x55d1a38c6333 in connect_cluster[abi:cxx11](void**) /home/jlayton/git/ceph/src/test/librados/test.cc:156
    #5 0x55d1a3750c5f in shutdown_racer_func /home/jlayton/git/ceph/src/test/librados/misc.cc:321
    #6 0x7f3aa17eb6f3  (/lib64/libstdc++.so.6+0xd76f3)

Thread T301 created by T0 here:
    #0 0x7f3aac9d4955 in pthread_create (/lib64/libasan.so.5+0x3a955)
    #1 0x7f3aa17eb9b8 in std::thread::_M_start_thread(std::unique_ptr<std::thread::_State, std::default_delete<std::thread::_State> >, void (*)()) (/lib64/libstdc++.so.6+0xd79b8)
    #2 0x55d1a38b5725 in void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/jlayton/git/ceph/src/googletest/googletest/src/gtest.cc:2439
    #3 0x55d1a38b5725 in void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/jlayton/git/ceph/src/googletest/googletest/src/gtest.cc:2475
    #4 0x55d1a3888d5a in testing::Test::Run() /home/jlayton/git/ceph/src/googletest/googletest/src/gtest.cc:2514
    #5 0x55d1a3888d5a in testing::Test::Run() /home/jlayton/git/ceph/src/googletest/googletest/src/gtest.cc:2504
    #6 0x55d1a388905c in testing::TestInfo::Run() /home/jlayton/git/ceph/src/googletest/googletest/src/gtest.cc:2690
    #7 0x55d1a388905c in testing::TestInfo::Run() /home/jlayton/git/ceph/src/googletest/googletest/src/gtest.cc:2663
    #8 0x55d1a388929e in testing::TestSuite::Run() /home/jlayton/git/ceph/src/googletest/googletest/src/gtest.cc:2822
    #9 0x55d1a388929e in testing::TestSuite::Run() /home/jlayton/git/ceph/src/googletest/googletest/src/gtest.cc:2801
    #10 0x55d1a388a63d in testing::internal::UnitTestImpl::RunAllTests() /home/jlayton/git/ceph/src/googletest/googletest/src/gtest.cc:5332
    #11 0x55d1a38b67e5 in bool testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /home/jlayton/git/ceph/src/googletest/googletest/src/gtest.cc:2439
    #12 0x55d1a38b67e5 in bool testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /home/jlayton/git/ceph/src/googletest/googletest/src/gtest.cc:2475
    #13 0x55d1a388abd5 in testing::UnitTest::Run() /home/jlayton/git/ceph/src/googletest/googletest/src/gtest.cc:4920
    #14 0x55d1a374f204 in RUN_ALL_TESTS() /home/jlayton/git/ceph/src/googletest/googletest/include/gtest/gtest.h:2472
    #15 0x55d1a374f204 in main /home/jlayton/git/ceph/src/test/unit.cc:45
    #16 0x7f3aa140ff42 in __libc_start_main (/lib64/libc.so.6+0x23f42)

SUMMARY: AddressSanitizer: heap-use-after-free /home/jlayton/git/ceph/src/common/ceph_timer.h:112 in ceph::timer_detail::timer<ceph::time_detail::coarse_mono_clock>::timer_thread()
Shadow bytes around the buggy address:
  0x0c16800f3d20: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fa fa
  0x0c16800f3d30: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c16800f3d40: fa fa fa fa fa fa fa fa fa fa fa fa 00 00 00 00
  0x0c16800f3d50: 00 00 00 00 00 00 00 00 00 00 fa fa fa fa fa fa
  0x0c16800f3d60: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
=>0x0c16800f3d70: fa fa fa fa fa fa fa fa[fd]fd fd fd fd fd fd fd
  0x0c16800f3d80: fd fd fd fd fd fd fa fa fa fa fa fa fa fa fa fa
  0x0c16800f3d90: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c16800f3da0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c16800f3db0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c16800f3dc0: fa fa fa fa fa fa fa fa fa 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
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
  Left alloca redzone:     ca
  Right alloca redzone:    cb
  Shadow gap:              cc
==20840==ABORTING