From: Yin Congmin Date: Tue, 29 Mar 2022 08:59:05 +0000 (+0800) Subject: librbd/cache/pwl: add basic metrics to ImageCacheState X-Git-Tag: v17.2.1~87^2~10 X-Git-Url: http://git-server-git.apps.pok.os.sepia.ceph.com/?a=commitdiff_plain;h=841df61fa3f9ab33685b07a57bcac0eda1666db2;p=ceph.git librbd/cache/pwl: add basic metrics to ImageCacheState 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 Signed-off-by: Ilya Dryomov (cherry picked from commit 769f3a06ecf85249c1473cbb6bab7503beb1ba78) --- diff --git a/doc/rbd/rbd-persistent-write-log-cache.rst b/doc/rbd/rbd-persistent-write-log-cache.rst index ae3809ba3f85..ed4980ba1e76 100644 --- a/doc/rbd/rbd-persistent-write-log-cache.rst +++ b/doc/rbd/rbd-persistent-write-log-cache.rst @@ -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 diff --git a/src/common/options/rbd.yaml.in b/src/common/options/rbd.yaml.in index 143241c2ba1a..770365db5104 100644 --- a/src/common/options/rbd.yaml.in +++ b/src/common/options/rbd.yaml.in @@ -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 diff --git a/src/librbd/cache/pwl/AbstractWriteLog.cc b/src/librbd/cache/pwl/AbstractWriteLog.cc index 0a01238e2654..5faf827f580e 100644 --- a/src/librbd/cache/pwl/AbstractWriteLog.cc +++ b/src/librbd/cache/pwl/AbstractWriteLog.cc @@ -315,7 +315,19 @@ void AbstractWriteLog::log_perf() { template void AbstractWriteLog::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::periodic_stats() { template void AbstractWriteLog::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 @@ -560,17 +569,14 @@ void AbstractWriteLog::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::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::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); }); diff --git a/src/librbd/cache/pwl/AbstractWriteLog.h b/src/librbd/cache/pwl/AbstractWriteLog.h index 63f82ab0f6a9..4905edde6e77 100644 --- a/src/librbd/cache/pwl/AbstractWriteLog.h +++ b/src/librbd/cache/pwl/AbstractWriteLog.h @@ -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 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; diff --git a/src/librbd/cache/pwl/ImageCacheState.cc b/src/librbd/cache/pwl/ImageCacheState.cc index 65de7b70f4e0..13fc28f87621 100644 --- a/src/librbd/cache/pwl/ImageCacheState.cc +++ b/src/librbd/cache/pwl/ImageCacheState.cc @@ -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::ImageCacheState(I *image_ctx, plugin::Api& plugin_api) : << dendl; ConfigProxy &config = image_ctx->config; - log_periodic_stats = config.get_val("rbd_persistent_cache_log_periodic_stats"); - cache_type = config.get_val("rbd_persistent_cache_mode"); + mode = config.get_val("rbd_persistent_cache_mode"); } template ImageCacheState::ImageCacheState( - I *image_ctx, JSONFormattable &f, plugin::Api& plugin_api) : + I *image_ctx, json_spirit::mObject &o, plugin::Api& 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("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 void ImageCacheState::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::clear_image_cache_state(Context *on_finish) { m_image_ctx, IMAGE_CACHE_STATE, on_finish); } -template -void ImageCacheState::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 ImageCacheState* ImageCacheState::create_image_cache_state( I* image_ctx, plugin::Api& plugin_api, int &r) { @@ -135,20 +141,20 @@ ImageCacheState* ImageCacheState::create_image_cache_state( cache_state = new ImageCacheState(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(image_ctx, plugin_api); } else { - cache_state = new ImageCacheState(image_ctx, f, plugin_api); + cache_state = new ImageCacheState(image_ctx, o, plugin_api); } } return cache_state; @@ -162,12 +168,13 @@ ImageCacheState* ImageCacheState::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(image_ctx, plugin_api); } else { - cache_state = new ImageCacheState(image_ctx, f, plugin_api); + cache_state = new ImageCacheState(image_ctx, o, plugin_api); } } return cache_state; diff --git a/src/librbd/cache/pwl/ImageCacheState.h b/src/librbd/cache/pwl/ImageCacheState.h index 7ea1412e26ff..512e8dc1b400 100644 --- a/src/librbd/cache/pwl/ImageCacheState.h +++ b/src/librbd/cache/pwl/ImageCacheState.h @@ -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 -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& plugin_api); - ImageCacheState(ImageCtxT* image_ctx, JSONFormattable& f, + ImageCacheState(ImageCtxT* image_ctx, json_spirit::mObject& f, plugin::Api& 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* create_image_cache_state( ImageCtxT* image_ctx, plugin::Api& plugin_api, int &r); diff --git a/src/librbd/cache/pwl/InitRequest.cc b/src/librbd/cache/pwl/InitRequest.cc index 13fc539dce90..65dac8b46ce0 100644 --- a/src/librbd/cache/pwl/InitRequest.cc +++ b/src/librbd/cache/pwl/InitRequest.cc @@ -85,8 +85,8 @@ void InitRequest::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 = diff --git a/src/test/librbd/cache/pwl/test_mock_ReplicatedWriteLog.cc b/src/test/librbd/cache/pwl/test_mock_ReplicatedWriteLog.cc index e01f1b585e45..180dd094097f 100644 --- a/src/test/librbd/cache/pwl/test_mock_ReplicatedWriteLog.cc +++ b/src/test/librbd/cache/pwl/test_mock_ReplicatedWriteLog.cc @@ -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("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\", \ diff --git a/src/test/librbd/cache/pwl/test_mock_SSDWriteLog.cc b/src/test/librbd/cache/pwl/test_mock_SSDWriteLog.cc index 822aebb0cbcd..9150fa3e8346 100644 --- a/src/test/librbd/cache/pwl/test_mock_SSDWriteLog.cc +++ b/src/test/librbd/cache/pwl/test_mock_SSDWriteLog.cc @@ -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("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\", \