Ceph » RADOS

Sounds like a use-after-free of some sort, unrelated to other crashes we've seen.

Scenario I can see after static analysis:

1. An instance of `TrackedOp` in `STATE_LIVE` is being dereferenced - the control flows to `TrackedOp::put`.
2. Reference counter hits `0` and `OpTracker::unregister_inflight_op(TrackedOp *i)` is being called.
3. There is a time window between zeroing the ref-counter and locking the shard.

class TrackedOp {
  // ...
  void put() {
    if (--nref == 0) {
      switch (state.load()) {
      // ...
      case STATE_LIVE:
        mark_event("done");
        tracker->unregister_inflight_op(this);
        break;
      // ...
      }
    }
  }
}

// ...
void OpTracker::unregister_inflight_op(TrackedOp *i)
{
  // caller checks;
  assert(i->state);

  uint32_t shard_index = i->seq % num_optracker_shards;
  ShardedTrackingData* sdata = sharded_in_flight_list[shard_index];
  assert(NULL != sdata);
  {
    Mutex::Locker locker(sdata->ops_in_flight_lock_sharded);
    `
    auto p = sdata->ops_in_flight_sharded.iterator_to(*i);
    sdata->ops_in_flight_sharded.erase(p);
  }

4. `OSD::get_health_metrics` jumps in between the update and the locking.

vector<DaemonHealthMetric> OSD::get_health_metrics()
{
  vector<DaemonHealthMetric> metrics;
  {
    // ...
    TrackedOpRef oldest_op;
    auto count_slow_ops = [&](TrackedOp& op) {
      // ...
      oldest_op = &op;
      // ...
    };
    if (op_tracker.visit_ops_in_flight(&oldest_secs, count_slow_ops)) {
      // ...
    }
  }

5. Assigning to `oldest_op` triggers the `TrackedOp::get()`/`TrackedOp::put()` pair, and thus `OpTracker::unregister_inflight_op` can be executed second time for same op while another call is in progress. This is dangerous as `boost::intrusive::list::iterator_to` must not be called on an object that doesn't belong to a given list instance (because e.g. it was erased earlier):

Requires: value must be a reference to a value inserted in a list.

related?

2018-05-18T03:29:21.427 INFO:tasks.ceph.mon.a.ovh098.stderr:*** Caught signal (Bus error) **
2018-05-18T03:29:21.427 INFO:tasks.ceph.mon.a.ovh098.stderr: in thread 7f60d12de700 thread_name:OpHistorySvc
2018-05-18T03:29:21.427 INFO:tasks.ceph.mon.a.ovh098.stderr: ceph version 13.1.0-129-gd3a3371 (d3a3371798df3316c173c967bc5300119f20cd22) mimic (rc)
2018-05-18T03:29:21.427 INFO:tasks.ceph.mon.a.ovh098.stderr: 1: (()+0x4b4120) [0x5619e499a120]
2018-05-18T03:29:21.427 INFO:tasks.ceph.mon.a.ovh098.stderr: 2: (()+0x11390) [0x7f60d8900390]
2018-05-18T03:29:21.428 INFO:tasks.ceph.mon.a.ovh098.stderr: 3: (RefCountedObject::put() const+0xb8) [0x5619e4791828]
2018-05-18T03:29:21.428 INFO:tasks.ceph.mon.a.ovh098.stderr: 4: (MonOpRequest::~MonOpRequest()+0x32) [0x5619e4791b22]
2018-05-18T03:29:21.428 INFO:tasks.ceph.mon.a.ovh098.stderr: 5: (std::_Rb_tree<std::pair<double, boost::intrusive_ptr<TrackedOp> >, std::pair<double, boost::intrusive_ptr<TrackedOp> >, std::_Identity<std::pair<double, boost::intrusive_ptr<TrackedOp> > >, std::less<std::pair<double, boost::intrusive_ptr<TrackedOp> > >, std::allocator<std::pair<double, boost::intrusive_ptr<TrackedOp> > > >::_M_erase_aux(std::_Rb_tree_const_iterator<std::pair<double, boost::intrusive_ptr<TrackedOp> > >)+0x83) [0x7f60d9014f83]
2018-05-18T03:29:21.428 INFO:tasks.ceph.mon.a.ovh098.stderr: 6: (OpHistory::cleanup(utime_t)+0x2b4) [0x7f60d9011c04]
2018-05-18T03:29:21.428 INFO:tasks.ceph.mon.a.ovh098.stderr: 7: (OpHistory::_insert_delayed(utime_t const&, boost::intrusive_ptr<TrackedOp>)+0x20c) [0x7f60d901258c]
2018-05-18T03:29:21.428 INFO:tasks.ceph.mon.a.ovh098.stderr: 8: (OpHistoryServiceThread::entry()+0xe9) [0x7f60d9012969]
2018-05-18T03:29:21.428 INFO:tasks.ceph.mon.a.ovh098.stderr: 9: (()+0x76ba) [0x7f60d88f66ba]
2018-05-18T03:29:21.428 INFO:tasks.ceph.mon.a.ovh098.stderr: 10: (clone()+0x6d) [0x7f60d7c5441d]
2018-05-18T03:29:21.428 INFO:tasks.ceph.mon.a.ovh098.stderr:2018-05-18 03:29:21.404 7f60d12de700 -1 *** Caught signal (Bus error) **
2018-05-18T03:29:21.428 INFO:tasks.ceph.mon.a.ovh098.stderr: in thread 7f60d12de700 thread_name:OpHistorySvc