Ceph » bluestore

it looks like Onode's put/get logic still has a flaw.
void BlueStore::Onode::put() {
int n = --nref;
if (n == 2) {
OnodeCacheShard* ocs = c->get_onode_cache();
std::lock_guard l(ocs->lock);
bool need_unpin = pinned;
pinned = pinned && nref > 2; // intentionally use > not >= as we have
// +1 due to pinned state

since this check plus assignment aren't atomic one might get a race with get():

if (++nref >= 2 && !pinned) {

when pinned is being assigned to false (due to nref <= 2) while get increments nref but gets old pinned value.
Hence we get nref > 2 but pinned set to false.

Looking for a solution different from doing that by a brute force and take locks unconditionally...

my x86 assembly made it atomic:

   1b068:    48 8b 45 c8              mov    -0x38(%rbp),%rax
   1b06c:    48 89 c7                 mov    %rax,%rdi
   1b06f:    e8 00 00 00 00           callq  1b074 <_ZN9BlueStore5Onode3getEv+0x28>
            1b070: R_X86_64_PLT32    _ZNSt13__atomic_baseIiEppEv-0x4
   1b074:    83 f8 01                 cmp    $0x1,%eax

But my compiled x86 definately shows that operator "&&" in ++nref >= 2 && !pinned makes whole action non-atomic.
Maybe this is the problem?

/a/kchai-2021-03-14_09:40:23-rados-wip-kefu-testing-2021-03-14-1612-distro-basic-smithi/5965024
/a/kchai-2021-03-14_09:40:23-rados-wip-kefu-testing-2021-03-14-1612-distro-basic-smithi/5964672

hmm... interesting finding:
void BlueStore::Collection::split_cache(
Collection *dest) {
ldout(store->cct, 10) << func << " to " << dest << dendl;

// lock (one or both) cache shards
  std::lock(cache->lock, dest->cache->lock);
  std::lock_guard l(cache->lock, std::adopt_lock);
  std::lock_guard l2(dest->cache->lock, std::adopt_lock);

looks like BlueStore::Collection::split_cache doesn't acquire OnodeCacheShard lock at all!!!!
The above locks are from BufferCacheShard, see

struct Collection : public CollectionImpl {
    BlueStore *store;
    OpSequencerRef osr;
    BufferCacheShard *cache;       ///< our cache shard

I'm not sure whether this is relevant to the bug or not though. But we should take care of that anyway...

Excellent catch Igor, I suspect that was probably introduced when the onode and buffer caches were split

probably related to the locking problem:

2021-03-21T05:50:39.807 INFO:tasks.ceph.osd.7.smithi111.stderr:*** Caught signal (Segmentation fault) **
2021-03-21T05:50:39.807 INFO:tasks.ceph.osd.7.smithi111.stderr: in thread 7ff00cbd3700 thread_name:tp_osd_tp
2021-03-21T05:50:39.809 INFO:tasks.rados.rados.0.smithi097.stdout:1329:  writing smithi09721916-848 from 605349 to 1177177 tid 1
2021-03-21T05:50:39.813 INFO:tasks.ceph.osd.7.smithi111.stderr: ceph version 16.1.0-1042-g6c172970 (6c1729700146219191135171ce9dd590f98cdb16) pacific (rc)
2021-03-21T05:50:39.813 INFO:tasks.ceph.osd.7.smithi111.stderr: 1: /lib/x86_64-linux-gnu/libpthread.so.0(+0x12980) [0x7ff02d95f980]
2021-03-21T05:50:39.813 INFO:tasks.ceph.osd.7.smithi111.stderr: 2: (std::_Hashtable<ghobject_t, std::pair<ghobject_t const, boost::intrusive_ptr<BlueStore::Onode> >, mempool::pool_allocator<(mempool::pool_index_t)4, std::pair<ghobject_t const, boost::intrusive_ptr<BlueStore::Onode> > >, std::__detail::_Select1st, std::equal_to<ghobject_t>, std::hash<ghobject_t>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<true, false, true> >::erase(std::__detail::_Node_const_iterator<std::pair<ghobject_t const, boost::intrusive_ptr<BlueStore::Onode> >, false, true>)+0x23) [0x558675d0fdb3]
2021-03-21T05:50:39.813 INFO:tasks.ceph.osd.7.smithi111.stderr: 3: (BlueStore::Collection::split_cache(BlueStore::Collection*)+0x1b2) [0x558675c6e8e2]
2021-03-21T05:50:39.813 INFO:tasks.ceph.osd.7.smithi111.stderr: 4: (BlueStore::_merge_collection(BlueStore::TransContext*, boost::intrusive_ptr<BlueStore::Collection>*, boost::intrusive_ptr<BlueStore::Collection>&, unsigned int)+0x14e) [0x558675cb051e]
2021-03-21T05:50:39.814 INFO:tasks.ceph.osd.7.smithi111.stderr: 5: (BlueStore::_txc_add_transaction(BlueStore::TransContext*, ceph::os::Transaction*)+0xc7c) [0x558675ce0bac]
2021-03-21T05:50:39.814 INFO:tasks.ceph.osd.7.smithi111.stderr: 6: (BlueStore::queue_transactions(boost::intrusive_ptr<ObjectStore::CollectionImpl>&, std::vector<ceph::os::Transaction, std::allocator<ceph::os::Transaction> >&, boost::intrusive_ptr<TrackedOp>, ThreadPool::TPHandle*)+0x2f2) [0x558675ce3112]
2021-03-21T05:50:39.814 INFO:tasks.ceph.osd.7.smithi111.stderr: 7: (ObjectStore::queue_transaction(boost::intrusive_ptr<ObjectStore::CollectionImpl>&, ceph::os::Transaction&&, boost::intrusive_ptr<TrackedOp>, ThreadPool::TPHandle*)+0x80) [0x5586757e8460]
2021-03-21T05:50:39.814 INFO:tasks.ceph.osd.7.smithi111.stderr: 8: (OSD::dispatch_context(PeeringCtx&, PG*, std::shared_ptr<OSDMap const>, ThreadPool::TPHandle*)+0x1db) [0x5586757822bb]
2021-03-21T05:50:39.814 INFO:tasks.ceph.osd.7.smithi111.stderr: 9: (OSD::dequeue_peering_evt(OSDShard*, PG*, std::shared_ptr<PGPeeringEvent>, ThreadPool::TPHandle&)+0x1e5) [0x5586757b2235]
2021-03-21T05:50:39.814 INFO:tasks.ceph.osd.7.smithi111.stderr: 10: (ceph::osd::scheduler::PGPeeringItem::run(OSD*, OSDShard*, boost::intrusive_ptr<PG>&, ThreadPool::TPHandle&)+0x50) [0x5586759e8e50]
2021-03-21T05:50:39.814 INFO:tasks.ceph.osd.7.smithi111.stderr: 11: (OSD::ShardedOpWQ::_process(unsigned int, ceph::heartbeat_handle_d*)+0xcd5) [0x5586757a3f35]
2021-03-21T05:50:39.814 INFO:tasks.ceph.osd.7.smithi111.stderr: 12: (ShardedThreadPool::shardedthreadpool_worker(unsigned int)+0x4ac) [0x558675e1ba3c]
2021-03-21T05:50:39.814 INFO:tasks.ceph.osd.7.smithi111.stderr: 13: (ShardedThreadPool::WorkThreadSharded::entry()+0x10) [0x558675e1ecf0]
2021-03-21T05:50:39.814 INFO:tasks.ceph.osd.7.smithi111.stderr: 14: /lib/x86_64-linux-gnu/libpthread.so.0(+0x76db) [0x7ff02d9546db]
2021-03-21T05:50:39.814 INFO:tasks.ceph.osd.7.smithi111.stderr: 15: clone()

In

  OnodeCacheShard* ocs = c->get_onode_cache();
  std::lock_guard l(ocs->lock);

I think it has much to do with our problem.
Attempting to verify it:
https://github.com/ceph/ceph/pull/40215/commits/6c53a25b9db1697a152b75a86eb75e1801664020