Ceph » bluestore

   -35> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 10 bluestore(bluestore.test_temp_dir) queue_transactions ch 0x562aede4d4a0 meta
   -34> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 20 bluestore(bluestore.test_temp_dir) _txc_create osr 0x562aeeb98500 = 0x562aeeaba300 seq 1
   -33> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 15 bluestore(bluestore.test_temp_dir) _create_collection meta bits 0
   -32> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 10 bluestore(bluestore.test_temp_dir) _create_collection meta bits 0 = 0
   -31> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 20 bluestore(bluestore.test_temp_dir).collection(meta 0x562aede4d4a0) get_onode oid #-1:83698d05:::fiemap_object:head# key 0x7f7fffffffffffffff83698d05216669'emap_object!='0xfffffffffffffffeffffffffffffffff'o'
   -30> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 20 bluestore(bluestore.test_temp_dir).collection(meta 0x562aede4d4a0)  r -2 v.len 0
   -29> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 15 bluestore(bluestore.test_temp_dir) _touch meta #-1:83698d05:::fiemap_object:head#
   -28> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 20 bluestore(bluestore.test_temp_dir) _assign_nid 1
   -27> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 10 bluestore(bluestore.test_temp_dir) _touch meta #-1:83698d05:::fiemap_object:head# = 0
   -26> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 15 bluestore(bluestore.test_temp_dir) _truncate meta #-1:83698d05:::fiemap_object:head# 0x186a0
   -25> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 15 bluestore(bluestore.test_temp_dir) _do_truncate meta #-1:83698d05:::fiemap_object:head# 0x186a0
   -24> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 10 bluestore(bluestore.test_temp_dir) _truncate meta #-1:83698d05:::fiemap_object:head# 0x186a0 = 0
   -23> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 10 bluestore(bluestore.test_temp_dir) _txc_calc_cost 0x562aeeaba300 cost 670352 (1 ios * 670000 + 352 bytes)
   -22> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 20 bluestore(bluestore.test_temp_dir) _txc_write_nodes txc 0x562aeeaba300 onodes 0x562aede72f00 shared_blobs 
   -21> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 20 bluestore.extentmap(0x562aede73008) update #-1:83698d05:::fiemap_object:head#
   -20> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 20 bluestore.extentmap(0x562aede73008) update  inline shard 2 bytes from 0 extents
   -19> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 20 bluestore(bluestore.test_temp_dir) _record_onode onode #-1:83698d05:::fiemap_object:head# is 30 (22 bytes onode + 2 bytes spanning blobs + 6 bytes inline extents)
   -18> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 20 bluestore(bluestore.test_temp_dir) _txc_finalize_kv txc 0x562aeeaba300 allocated 0x[] released 0x[]

returns to caller. some other stuff happens,

   -17> 2019-10-25T07:56:57.166+0000 7fc87b4f2700  5 prioritycache tune_memory target: 4294967296 mapped: 18292736 unmapped: 65994752 heap: 84287488 old mem: 134217728 new mem: 2833868543
   -16> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 10 bluestore(bluestore.test_temp_dir) _txc_state_proc txc 0x562aeeaba300 prepare
   -15> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 20 bluestore(bluestore.test_temp_dir) _txc_finish_io 0x562aeeaba300
   -14> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 10 bluestore(bluestore.test_temp_dir) _txc_state_proc txc 0x562aeeaba300 io_done
   -13> 2019-10-25T07:56:57.166+0000 7fc8736e8700 20 bluestore(bluestore.test_temp_dir) _kv_sync_thread wake
   -12> 2019-10-25T07:56:57.166+0000 7fc8736e8700 20 bluestore(bluestore.test_temp_dir) _kv_sync_thread committing 1 submitting 1 deferred done 0 stable 0

and then the caller tries another operation on fiemap_object,

   -11> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 20 bluestore(bluestore.test_temp_dir).collection(meta 0x562aede4d4a0) get_onode oid #-1:83698d05:::fiemap_object:head# key 0x7f7fffffffffffffff83698d05216669'emap_object!='0xfffffffffffffffeffffffffffffffff'o'
   -10> 2019-10-25T07:56:57.166+0000 7fc891b6fd40 20 bluestore(bluestore.test_temp_dir).collection(meta 0x562aede4d4a0)  r -2 v.len 0
...
     0> 2019-10-25T07:56:57.171+0000 7fc891b6fd40 -1 *** Caught signal (Aborted) **
 in thread 7fc891b6fd40 thread_name:ceph_test_objec

 ceph version 15.0.0-6444-g7c42079 (7c420790fe0da8bcfca0bd14632a10583d2cbd3e) octopus (dev)
 1: (()+0xf5d0) [0x7fc8917695d0]
 2: (gsignal()+0x37) [0x7fc88558f2c7]
 3: (abort()+0x148) [0x7fc8855909b8]
 4: (__gnu_cxx::__verbose_terminate_handler()+0x165) [0x7fc885e9e7d5]
 5: (()+0x5e746) [0x7fc885e9c746]
 6: (()+0x5e773) [0x7fc885e9c773]
 7: (()+0x5e993) [0x7fc885e9c993]
 8: (std::enable_if<denc_traits<std::map<unsigned long, unsigned long, std::less<unsigned long>, std::allocator<std::pair<unsigned long const, unsigned long> > >, void>::supported&&(!denc_traits<std::map<unsigned long, unsigned long, std::less<unsigned long>, std::allocator<std::pair<unsigned long const, unsigned long> > >, void>::need_contiguous), void>::type ceph::decode<std::map<unsigned long, unsigned long, std::less<unsigned long>, std::allocator<std::pair<unsigned long const, unsigned long> > >, denc_traits<std::map<unsigned long, unsigned long, std::less<unsigned long>, std::allocator<std::pair<unsigned long const, unsigned long> > >, void> >(std::map<unsigned long, unsigned long, std::less<unsigned long>, std::allocator<std::pair<unsigned long const, unsigned long> > >&, ceph::buffer::v14_2_0::list::iterator_impl<true>&)+0x328) [0x562aeb1b5848]
 9: (StoreTest_FiemapEmpty_Test::TestBody()+0x3e3) [0x562aeb123d43]
 10: (void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*)+0x87) [0x562aeb41af97]

and the object is not there (causing the test to crash).

/a/sage-2019-10-25_05:04:47-rados-wip-sage2-testing-2019-10-24-1944-distro-basic-smithi/4442768