]> git.apps.os.sepia.ceph.com Git - ceph.git/commitdiff
librbd/cache/pwl: add basic metrics to ImageCacheState
authorYin Congmin <congmin.yin@intel.com>
Tue, 29 Mar 2022 08:59:05 +0000 (16:59 +0800)
committerIlya Dryomov <idryomov@gmail.com>
Mon, 11 Apr 2022 06:26:47 +0000 (08:26 +0200)
Add basic metrics to ImageCacheState and persist them, including
allocated_bytes, cached_bytes, dirty_bytes, free_bytes and hit/miss
info.

Leverage periodic_stats() timer to call update_image_cache_state.
In order to avoid outputting too much debug information, the original
statistics output log level is changed to 5.

Switch to json_spirit for encoding because encode_json encodes bool as
"true"/"false" string.

Remove rbd_persistent_cache_log_periodic_stats option because we need
to always update cache state.

[ idryomov: add cached_bytes and hits_partial; report misses and
  miss_bytes instead of respective totals; naming ]

Fixes: https://tracker.ceph.com/issues/50614
Signed-off-by: Yin Congmin <congmin.yin@intel.com>
Signed-off-by: Ilya Dryomov <idryomov@gmail.com>
doc/rbd/rbd-persistent-write-log-cache.rst
src/common/options/rbd.yaml.in
src/librbd/cache/pwl/AbstractWriteLog.cc
src/librbd/cache/pwl/AbstractWriteLog.h
src/librbd/cache/pwl/ImageCacheState.cc
src/librbd/cache/pwl/ImageCacheState.h
src/librbd/cache/pwl/InitRequest.cc
src/test/librbd/cache/pwl/test_mock_ReplicatedWriteLog.cc
src/test/librbd/cache/pwl/test_mock_SSDWriteLog.cc

index ae3809ba3f85859a9335c46685b9c5c0a2f9148c..ed4980ba1e76b22989663d205ae43154dd8d4bc6 100644 (file)
@@ -60,10 +60,6 @@ Here are some cache configuration settings:
 - ``rbd_persistent_cache_size`` The cache size per image. The minimum cache
   size is 1 GB.
 
-- ``rbd_persistent_cache_log_periodic_stats`` This is a debug option. It is
-  used to emit periodic perf stats to the debug log if ``debug rbd pwl`` is
-  set to ``1`` or higher.
-
 The above configurations can be set per-host, per-pool, per-image etc. Eg, to
 set per-host, add the overrides to the appropriate `section`_ in the host's
 ``ceph.conf`` file. To set per-pool, per-image, etc, please refer to the
index 143241c2ba1abfc1412fb5237f78b6fb4652e2e6..770365db510492abd80ed695dc0f46297153acec 100644 (file)
@@ -830,13 +830,6 @@ options:
   - disabled
   - rwl
   - ssd
-- name: rbd_persistent_cache_log_periodic_stats
-  type: bool
-  level: advanced
-  desc: emit periodic perf stats to debug log
-  default: false
-  services:
-  - rbd
 - name: rbd_persistent_cache_size
   type: uint
   level: advanced
index 0a01238e265443aa531eb7ea5c5a4c6bb86b684e..5faf827f580ea9513d51932a75a6022181b78b04 100644 (file)
@@ -315,7 +315,19 @@ void AbstractWriteLog<I>::log_perf() {
 template <typename I>
 void AbstractWriteLog<I>::periodic_stats() {
   std::lock_guard locker(m_lock);
-  ldout(m_image_ctx.cct, 1) << "STATS: m_log_entries=" << m_log_entries.size()
+  m_cache_state->allocated_bytes = m_bytes_allocated;
+  m_cache_state->cached_bytes = m_bytes_cached;
+  m_cache_state->dirty_bytes = m_bytes_dirty;
+  m_cache_state->free_bytes = m_bytes_allocated_cap - m_bytes_allocated;
+  m_cache_state->hits_full = m_perfcounter->get(l_librbd_pwl_rd_hit_req);
+  m_cache_state->hits_partial = m_perfcounter->get(l_librbd_pwl_rd_part_hit_req);
+  m_cache_state->misses = m_perfcounter->get(l_librbd_pwl_rd_req) -
+      m_cache_state->hits_full - m_cache_state->hits_partial;
+  m_cache_state->hit_bytes = m_perfcounter->get(l_librbd_pwl_rd_hit_bytes);
+  m_cache_state->miss_bytes = m_perfcounter->get(l_librbd_pwl_rd_bytes) -
+      m_cache_state->hit_bytes;
+  update_image_cache_state();
+  ldout(m_image_ctx.cct, 5) << "STATS: m_log_entries=" << m_log_entries.size()
                             << ", m_dirty_log_entries=" << m_dirty_log_entries.size()
                             << ", m_free_log_entries=" << m_free_log_entries
                             << ", m_bytes_allocated=" << m_bytes_allocated
@@ -332,15 +344,12 @@ void AbstractWriteLog<I>::periodic_stats() {
 template <typename I>
 void AbstractWriteLog<I>::arm_periodic_stats() {
   ceph_assert(ceph_mutex_is_locked(*m_timer_lock));
-  if (m_periodic_stats_enabled) {
-    m_timer_ctx = new LambdaContext(
-      [this](int r) {
-        /* m_timer_lock is held */
-        periodic_stats();
-        arm_periodic_stats();
-      });
-    m_timer->add_event_after(LOG_STATS_INTERVAL_SECONDS, m_timer_ctx);
-  }
+  m_timer_ctx = new LambdaContext([this](int r) {
+      /* m_timer_lock is held */
+      periodic_stats();
+      arm_periodic_stats();
+    });
+  m_timer->add_event_after(LOG_STATS_INTERVAL_SECONDS, m_timer_ctx);
 }
 
 template <typename I>
@@ -560,17 +569,14 @@ void AbstractWriteLog<I>::pwl_init(Context *on_finish, DeferredContexts &later)
   // Start the thread
   m_thread_pool.start();
 
-  m_periodic_stats_enabled = m_cache_state->log_periodic_stats;
   /* Do these after we drop lock */
   later.add(new LambdaContext([this](int r) {
-    if (m_periodic_stats_enabled) {
       /* Log stats for the first time */
       periodic_stats();
       /* Arm periodic stats logging for the first time */
       std::lock_guard timer_locker(*m_timer_lock);
       arm_periodic_stats();
-    }
-  }));
+    }));
   m_image_ctx.op_work_queue->queue(on_finish, 0);
 }
 
@@ -640,13 +646,7 @@ void AbstractWriteLog<I>::shut_down(Context *on_finish) {
     [this, ctx](int r) {
       ldout(m_image_ctx.cct, 6) << "image cache cleaned" << dendl;
       Context *next_ctx = override_ctx(r, ctx);
-      bool periodic_stats_enabled = m_periodic_stats_enabled;
-      m_periodic_stats_enabled = false;
-
-      if (periodic_stats_enabled) {
-        /* Log stats one last time if they were enabled */
-        periodic_stats();
-      }
+      periodic_stats();
       {
         std::lock_guard locker(m_lock);
         check_image_cache_state_clean();
@@ -681,9 +681,7 @@ void AbstractWriteLog<I>::shut_down(Context *on_finish) {
         /* Flush all writes to OSDs (unless disabled) and wait for all
            in-progress flush writes to complete */
         ldout(m_image_ctx.cct, 6) << "flushing" << dendl;
-        if (m_periodic_stats_enabled) {
-          periodic_stats();
-        }
+        periodic_stats();
       }
       flush_dirty_entries(next_ctx);
     });
index 63f82ab0f6a97c0ca07536f340a87241d0b177c8..4905edde6e770d1aba52078e916e935bc3a69c04 100644 (file)
@@ -212,8 +212,6 @@ private:
   /* Throttle writes concurrently allocating & replicating */
   unsigned int m_free_lanes = pwl::MAX_CONCURRENT_WRITES;
 
-  /* Initialized from config, then set false during shutdown */
-  std::atomic<bool> m_periodic_stats_enabled = {false};
   SafeTimer *m_timer = nullptr; /* Used with m_timer_lock */
   mutable ceph::mutex *m_timer_lock = nullptr; /* Used with and by m_timer */
   Context *m_timer_ctx = nullptr;
index 65de7b70f4e0e671ef5aa98aa0c461f8429c5994..13fc28f87621de03925bc29747f4ebc7ee046dfa 100644 (file)
@@ -7,7 +7,6 @@
 #include "librbd/ImageCtx.h"
 #include "librbd/Operations.h"
 #include "common/config_proxy.h"
-#include "common/ceph_json.h"
 #include "common/environment.h"
 #include "common/hostname.h"
 #include "librbd/plugin/Api.h"
@@ -25,13 +24,15 @@ namespace pwl {
 using namespace std;
 
 namespace {
-bool get_json_format(const std::string& s, JSONFormattable *f) {
-  JSONParser p;
-  bool success = p.parse(s.c_str(), s.size());
-  if (success) {
-    decode_json_obj(*f, &p);
+bool get_json_format(const std::string& s, json_spirit::mObject *o) {
+  json_spirit::mValue json_root;
+  if (!json_spirit::read(s.c_str(), json_root)) {
+    return false;
+  } else {
+    auto cache_state_root = json_root.get_obj()["persistent_cache"];
+    *o = cache_state_root.get_obj();
   }
-  return success;
+  return true;
 }
 } // namespace
 
@@ -42,41 +43,57 @@ ImageCacheState<I>::ImageCacheState(I *image_ctx, plugin::Api<I>& plugin_api) :
                             << dendl;
 
   ConfigProxy &config = image_ctx->config;
-  log_periodic_stats = config.get_val<bool>("rbd_persistent_cache_log_periodic_stats");
-  cache_type = config.get_val<std::string>("rbd_persistent_cache_mode");
+  mode = config.get_val<std::string>("rbd_persistent_cache_mode");
 }
 
 template <typename I>
 ImageCacheState<I>::ImageCacheState(
-    I *image_ctx, JSONFormattable &f, plugin::Api<I>& plugin_api) :
+    I *image_ctx, json_spirit::mObject &o, plugin::Api<I>& plugin_api) :
     m_image_ctx(image_ctx), m_plugin_api(plugin_api) {
   ldout(image_ctx->cct, 20) << "Initialize RWL cache state with data from "
                             << "server side"<< dendl;
 
-  present = (bool)f["present"];
-  empty = (bool)f["empty"];
-  clean = (bool)f["clean"];
-  cache_type = f["cache_type"];
-  host = f["pwl_host"];
-  path = f["pwl_path"];
-  uint64_t pwl_size;
-  std::istringstream iss(f["pwl_size"]);
-  iss >> pwl_size;
-  size = pwl_size;
-
-  // Others from config
-  ConfigProxy &config = image_ctx->config;
-  log_periodic_stats = config.get_val<bool>("rbd_persistent_cache_log_periodic_stats");
+  try {
+    present = o["present"].get_bool();
+    empty = o["empty"].get_bool();
+    clean = o["clean"].get_bool();
+    host = o["host"].get_str();
+    path = o["path"].get_str();
+    mode = o["mode"].get_str();
+    size = o["size"].get_uint64();
+  } catch (std::runtime_error& e) {
+    lderr(image_ctx->cct) << "failed to parse cache state: " << e.what()
+                          << dendl;
+  }
 }
 
 template <typename I>
 void ImageCacheState<I>::write_image_cache_state(Context *on_finish) {
+  stats_timestamp = ceph_clock_now();
   std::shared_lock owner_lock{m_image_ctx->owner_lock};
-  JSONFormattable f;
-  ::encode_json(IMAGE_CACHE_STATE.c_str(), *this, &f);
-  std::ostringstream oss;
-  f.flush(oss);
-  std::string image_state_json = oss.str();
+  json_spirit::mObject o;
+  o["present"] = present;
+  o["empty"] = empty;
+  o["clean"] = clean;
+  o["host"] = host;
+  o["path"] = path;
+  o["mode"] = mode;
+  o["size"] = size;
+  o["stats_timestamp"] = stats_timestamp.sec();
+  o["allocated_bytes"] = allocated_bytes;
+  o["cached_bytes"] = cached_bytes;
+  o["dirty_bytes"] = dirty_bytes;
+  o["free_bytes"] = free_bytes;
+  o["hits_full"] = hits_full;
+  o["hits_partial"] = hits_partial;
+  o["misses"] = misses;
+  o["hit_bytes"] = hit_bytes;
+  o["miss_bytes"] = miss_bytes;
+  json_spirit::mObject cache_state_obj;
+  cache_state_obj["persistent_cache"] = o;
+  stringstream json_string;
+  json_spirit::write(cache_state_obj, json_string);
+  std::string image_state_json = json_string.str();
 
   ldout(m_image_ctx->cct, 20) << __func__ << " Store state: "
                               << image_state_json << dendl;
@@ -92,17 +109,6 @@ void ImageCacheState<I>::clear_image_cache_state(Context *on_finish) {
     m_image_ctx, IMAGE_CACHE_STATE, on_finish);
 }
 
-template <typename I>
-void ImageCacheState<I>::dump(ceph::Formatter *f) const {
-  ::encode_json("present", present, f);
-  ::encode_json("empty", empty, f);
-  ::encode_json("clean", clean, f);
-  ::encode_json("cache_type", cache_type, f);
-  ::encode_json("pwl_host", host, f);
-  ::encode_json("pwl_path", path, f);
-  ::encode_json("pwl_size", size, f);
-}
-
 template <typename I>
 ImageCacheState<I>* ImageCacheState<I>::create_image_cache_state(
     I* image_ctx, plugin::Api<I>& plugin_api, int &r) {
@@ -135,20 +141,20 @@ ImageCacheState<I>* ImageCacheState<I>::create_image_cache_state(
     cache_state = new ImageCacheState<I>(image_ctx, plugin_api);
   } else {
     ceph_assert(!cache_state_str.empty());
-    JSONFormattable f;
-    bool success = get_json_format(cache_state_str, &f);
+    json_spirit::mObject o;
+    bool success = get_json_format(cache_state_str, &o);
     if (!success) {
-      lderr(image_ctx->cct) << "Failed to parse cache state: "
+      lderr(image_ctx->cct) << "failed to parse cache state: "
                             << cache_state_str << dendl;
       r = -EINVAL;
       return nullptr;
     }
 
-    bool cache_exists = (bool)f["present"];
+    bool cache_exists = o["present"].get_bool();
     if (!cache_exists) {
       cache_state = new ImageCacheState<I>(image_ctx, plugin_api);
     } else {
-      cache_state = new ImageCacheState<I>(image_ctx, f, plugin_api);
+      cache_state = new ImageCacheState<I>(image_ctx, o, plugin_api);
     }
   }
   return cache_state;
@@ -162,12 +168,13 @@ ImageCacheState<I>* ImageCacheState<I>::get_image_cache_state(
   cls_client::metadata_get(&image_ctx->md_ctx, image_ctx->header_oid,
                           IMAGE_CACHE_STATE, &cache_state_str);
   if (!cache_state_str.empty()) {
-    JSONFormattable f;
-    bool success = get_json_format(cache_state_str, &f);
+    json_spirit::mObject o;
+    bool success = get_json_format(cache_state_str, &o);
     if (!success) {
+      lderr(image_ctx->cct) << "failed to parse cache state" << dendl;
       cache_state = new ImageCacheState<I>(image_ctx, plugin_api);
     } else {
-      cache_state = new ImageCacheState<I>(image_ctx, f, plugin_api);
+      cache_state = new ImageCacheState<I>(image_ctx, o, plugin_api);
     }
   }
   return cache_state;
index 7ea1412e26ff88be254077f77b2a37ea7a6f29ae..512e8dc1b4001b8995ddea9151a0f83f78a8e6a5 100644 (file)
@@ -4,11 +4,11 @@
 #ifndef CEPH_LIBRBD_CACHE_RWL_IMAGE_CACHE_STATE_H
 #define CEPH_LIBRBD_CACHE_RWL_IMAGE_CACHE_STATE_H
 
+#include "json_spirit/json_spirit.h"
 #include "librbd/ImageCtx.h"
 #include "librbd/cache/Types.h"
 #include <string>
 
-class JSONFormattable;
 namespace ceph {
   class Formatter;
 }
@@ -31,33 +31,41 @@ public:
   bool clean = true;
   std::string host;
   std::string path;
-  std::string cache_type;
+  std::string mode;
   uint64_t size = 0;
-  bool log_periodic_stats;
+  /* After reloading, the following data does not need to be read,
+   * but recalculated. */
+  utime_t stats_timestamp;
+  uint64_t allocated_bytes = 0;
+  uint64_t cached_bytes = 0;
+  uint64_t dirty_bytes = 0;
+  uint64_t free_bytes = 0;
+  uint64_t hits_full = 0;
+  uint64_t hits_partial = 0;
+  uint64_t misses = 0;
+  uint64_t hit_bytes = 0;
+  uint64_t miss_bytes = 0;
 
   ImageCacheState(ImageCtxT* image_ctx, plugin::Api<ImageCtxT>& plugin_api);
 
-  ImageCacheState(ImageCtxT* image_ctx, JSONFormattable& f,
+  ImageCacheState(ImageCtxT* image_ctx, json_spirit::mObject& f,
                   plugin::Api<ImageCtxT>& plugin_api);
 
   ~ImageCacheState() {}
 
-  ImageCacheType get_image_cache_type() const {
-    if (cache_type == "rwl") {
+  ImageCacheType get_image_cache_mode() const {
+    if (mode == "rwl") {
       return IMAGE_CACHE_TYPE_RWL;
-    } else if (cache_type == "ssd") {
+    } else if (mode == "ssd") {
       return IMAGE_CACHE_TYPE_SSD;
     }
     return IMAGE_CACHE_TYPE_UNKNOWN;
   }
 
-
   void write_image_cache_state(Context *on_finish);
 
   void clear_image_cache_state(Context *on_finish);
 
-  void dump(ceph::Formatter *f) const;
-
   static ImageCacheState<ImageCtxT>* create_image_cache_state(
     ImageCtxT* image_ctx, plugin::Api<ImageCtxT>& plugin_api, int &r);
 
index 13fc539dce90027dc3f1cf2678a6567970bd0cc5..65dac8b46ce008f803cc31e95e1e58a25fe543f9 100644 (file)
@@ -85,8 +85,8 @@ void InitRequest<I>::get_image_cache_state() {
     return;
   }
 
-  auto cache_type = cache_state->get_image_cache_type();
-  switch(cache_type) {
+  auto mode = cache_state->get_image_cache_mode();
+  switch (mode) {
     #ifdef WITH_RBD_RWL
     case cache::IMAGE_CACHE_TYPE_RWL:
       m_image_cache =
index e01f1b585e45d511dde419b2608923ec399ad2ad..180dd094097f450120ec01a620ce0c6886c648ed 100644 (file)
@@ -75,7 +75,6 @@ struct TestMockCacheReplicatedWriteLog : public TestMockFixture {
                             bool present, bool empty, bool clean,
                             string host, string path,
                             uint64_t size) {
-    ConfigProxy &config = image_ctx->config;
     ASSERT_EQ(present, state.present);
     ASSERT_EQ(empty, state.empty);
     ASSERT_EQ(clean, state.clean);
@@ -83,8 +82,6 @@ struct TestMockCacheReplicatedWriteLog : public TestMockFixture {
     ASSERT_EQ(host, state.host);
     ASSERT_EQ(path, state.path);
     ASSERT_EQ(size, state.size);
-    ASSERT_EQ(config.get_val<bool>("rbd_persistent_cache_log_periodic_stats"),
-             state.log_periodic_stats);
   }
 
   void expect_op_work_queue(MockImageCtx& mock_image_ctx) {
@@ -135,19 +132,17 @@ TEST_F(TestMockCacheReplicatedWriteLog, init_state_write) {
   ASSERT_EQ(0, finish_ctx.wait());
 }
 
-static void get_jf(const string& s, JSONFormattable *f)
+static void get_jf(const string& s, json_spirit::mObject *f)
 {
-  JSONParser p;
-  bool result = p.parse(s.c_str(), s.size());
+  json_spirit::mValue json_root;
+  bool result = json_spirit::read(s.c_str(), json_root);
   if (!result) {
-    cout << "Failed to parse: '" << s << "'" << std::endl;
+    cout << "failed to parse: '" << s << "'" << std::endl;
+  } else {
+    auto cache_state_root = json_root.get_obj()["persistent_cache"];
+    *f = cache_state_root.get_obj();
   }
   ASSERT_EQ(true, result);
-  try {
-    decode_json_obj(*f, &p);
-  } catch (JSONDecoder::err& e) {
-    ASSERT_TRUE(0 == "Failed to decode JSON object");
-  }
 }
 
 TEST_F(TestMockCacheReplicatedWriteLog, init_state_json_write) {
@@ -156,7 +151,7 @@ TEST_F(TestMockCacheReplicatedWriteLog, init_state_json_write) {
 
   MockImageCtx mock_image_ctx(*ictx);
 
-  JSONFormattable f;
+  json_spirit::mObject f;
   string strf = "{ \"present\": \"1\", \"empty\": \"0\", \"clean\": \"0\", \
                    \"pwl_host\": \"testhost\", \
                    \"pwl_path\": \"/tmp\", \
index 822aebb0cbcdc0d77c2ec986407625fa4ba8d903..9150fa3e8346c9aef179dcaf61995651aca7e8bb 100644 (file)
@@ -77,7 +77,6 @@ struct TestMockCacheSSDWriteLog : public TestMockFixture {
                             bool present, bool empty, bool clean,
                             string host, string path,
                             uint64_t size) {
-    ConfigProxy &config = image_ctx->config;
     ASSERT_EQ(present, state.present);
     ASSERT_EQ(empty, state.empty);
     ASSERT_EQ(clean, state.clean);
@@ -85,8 +84,6 @@ struct TestMockCacheSSDWriteLog : public TestMockFixture {
     ASSERT_EQ(host, state.host);
     ASSERT_EQ(path, state.path);
     ASSERT_EQ(size, state.size);
-    ASSERT_EQ(config.get_val<bool>("rbd_persistent_cache_log_periodic_stats"),
-             state.log_periodic_stats);
   }
 
   void expect_op_work_queue(MockImageCtx& mock_image_ctx) {
@@ -137,19 +134,17 @@ TEST_F(TestMockCacheSSDWriteLog, init_state_write) {
   ASSERT_EQ(0, finish_ctx.wait());
 }
 
-static void get_jf(const string& s, JSONFormattable *f)
+static void get_jf(const string& s, json_spirit::mObject *f)
 {
-  JSONParser p;
-  bool result = p.parse(s.c_str(), s.size());
+  json_spirit::mValue json_root;
+  bool result = json_spirit::read(s.c_str(), json_root);
   if (!result) {
-    cout << "Failed to parse: '" << s << "'" << std::endl;
+    cout << "failed to parse: '" << s << "'" << std::endl;
+  } else {
+    auto cache_state_root = json_root.get_obj()["persistent_cache"];
+    *f = cache_state_root.get_obj();
   }
   ASSERT_EQ(true, result);
-  try {
-    decode_json_obj(*f, &p);
-  } catch (JSONDecoder::err& e) {
-    ASSERT_TRUE(0 == "Failed to decode JSON object");
-  }
 }
 
 TEST_F(TestMockCacheSSDWriteLog, init_state_json_write) {
@@ -158,7 +153,7 @@ TEST_F(TestMockCacheSSDWriteLog, init_state_json_write) {
 
   MockImageCtx mock_image_ctx(*ictx);
 
-  JSONFormattable f;
+  json_spirit::mObject f;
   string strf = "{ \"present\": \"1\", \"empty\": \"0\", \"clean\": \"0\", \
                    \"pwl_host\": \"testhost\", \
                    \"pwl_path\": \"/tmp\", \