Ceph » RADOS

https://jenkins.ceph.com/job/ceph-pull-requests-arm64/73027/

/home/jenkins-build/build/workspace/ceph-pull-requests-arm64/src/test/cli/crushtool/reclassify.t: failed
--- /home/jenkins-build/build/workspace/ceph-pull-requests-arm64/src/test/cli/crushtool/reclassify.t
+++ /home/jenkins-build/build/workspace/ceph-pull-requests-arm64/src/test/cli/crushtool/reclassify.t.err
@@ -408,6 +408,9 @@
   rule 0 had 0/10240 mismatched mappings (0)
   rule 1 had 0/10240 mismatched mappings (0)
   maps appear equivalent
+  /usr/lib/gcc/aarch64-linux-gnu/11/../../../../include/c++/11/bits/unique_ptr.h:659: typename std::add_lvalue_reference<element_type>::type std::unique_ptr<mempool::shard_t[]>::operator[](size_t) const [_Tp = mempool::shard_t[], _Dp = std::default_delete<mempool::shard_t[]>]: Assertion 'get() != pointer()' failed.
+  *** Caught signal (Aborted) **
+   in thread ffff7c3e1c80 thread_name:service

Not reproduced this yet, but saw something similar in a bluestore unittest while making the change - in that case it was a multi-threaded test case that was exiting while threads that were still running tried to access mempool. exit runs the destructors including some mempool destructors causing a use after free bug. Prior to my recent change to add a unique_ptr these silently passed, now they will cause asserts. As this is a timing window between threads it probably won't happen every run.

The crashes from crushtool are happening at the end of the test as it exits, however it does all its work on the main thread, there are two threads created by global/common but these should be idle.

Will investigate further

It is a use after free bug:

src/common/ceph_context.cc has a CephContextServiceThread:

  void *entry() override
  {
    while (1) {
      std::unique_lock l(_lock);
      if (_exit_thread) {
        break;
      }

      if (_cct->_conf->heartbeat_interval) {
        auto interval = ceph::make_timespan(_cct->_conf->heartbeat_interval);
        _cond.wait_for(l, interval);
      } else
        _cond.wait(l);

      if (_exit_thread) {
        break;
      }

      if (_reopen_logs) {
        _cct->_log->reopen_log_file();
        _reopen_logs = false;
      }
      _cct->_heartbeat_map->check_touch_file();

      // refresh the perf coutners
      _cct->_refresh_perf_values();
    }
    return NULL;
  }

heartbeat_interval defaults to 5 seconds so once every 5 seconds this thread calls _refresh_perf_values() which updates all the mempool counters.
However this thread doesn't get terminated until the CephContext destructor gets called, which never happens in crushtool.

Therefore it is possible that the heartbeat tickoccurs and _refresh_perf_values() gets called just as the main thread in crushtool is exiting and running the mempool destructors. Presumably the timing of arm64 make checks tests makes it more likely that the test has been running 5 seconds??

The logs above have

in thread ffff7c3e1c80 thread_name:service

that confirms its this thread that is asserting.

Why isn't the CephContext destructor being called?

This code in src/tools/crushtool.cc is calling cct->get() which is blocking the destructor from being called. If this line is commented out then the destructor runs (confirmed with gdb).

  auto cct = global_init(NULL, empty_args, CEPH_ENTITY_TYPE_CLIENT,
                         CODE_ENVIRONMENT_UTILITY,
                         CINIT_FLAG_NO_DEFAULT_CONFIG_FILE);
  // crushtool times out occasionally when quits. so do not
  // release the g_ceph_context.
  cct->get();
  common_init_finish(g_ceph_context);

https://github.com/ceph/ceph/commit/d305cc51b18cbf4b2757bbacb5d43324461306a9 added this code, but provides no further explanation about the timeout/hang.

Don't really want to remove this without understanding why the timeout/hang occurred. We could stop this thread being created by setting
CINIT_FLAG_NO_DAEMON_ACTIONS on the global_init call, this feels like a bit of a hack but might be the safest fix.

Bill Scales wrote in #note-4:

heartbeat_interval defaults to 5 seconds so once every 5 seconds this thread calls _refresh_perf_values() which updates all the mempool counters.
However this thread doesn't get terminated until the CephContext destructor gets called, which never happens in crushtool.

Therefore it is possible that the heartbeat tickoccurs and _refresh_perf_values() gets called just as the main thread in crushtool is exiting and running the mempool destructors. Presumably the timing of arm64 make checks tests makes it more likely that the test has been running 5 seconds??

thanks Bill. do you know what controls the lifetime of these mempools? if they aren't owned by the CephContext, maybe they should be?

Don't really want to remove this without understanding why the timeout/hang occurred. We could stop this thread being created by setting
CINIT_FLAG_NO_DAEMON_ACTIONS on the global_init call, this feels like a bit of a hack but might be the safest fix.

CINIT_FLAG_NO_DAEMON_ACTIONS does sound reasonable for command-line tools like this

In QA.

Still in QA.

Not sure if related or no, but we had a similar crash in Crimson main tests:
https://tracker.ceph.com/issues/71478#note-3