Skip to content

Commit

Permalink
Merge pull request ceph#45684 from CongMinYin/pwl-add-stats
Browse files Browse the repository at this point in the history 
librbd/cache/pwl: add pwl metrics in "rbd status" display

Reviewed-by: Ilya Dryomov <idryomov@gmail.com>
  • Loading branch information
@idryomov
idryomov authored Apr 12, 2022
2 parents d104ae5 + e996fd8 commit 3c55687
Show file tree
Hide file tree
Showing 14 changed files with 293 additions and 220 deletions.
28 changes: 19 additions & 9 deletions doc/rbd/rbd-persistent-write-log-cache.rst
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -79,15 +75,29 @@ users may use the command ``rbd status``. ::
rbd status {pool-name}/{image-name}

The status of the cache is shown, including present, clean, cache size and the
location. Currently the status is updated only at the time the cache is opened
and closed and therefore may appear to be out of date (e.g. show that the cache
is clean when it is actually dirty).
location as well as some basic metrics.

For example::

$ rbd status rbd/foo
Watchers: none
Image cache state: {"present":"true","empty":"false","clean":"true","cache_type":"ssd","pwl_host":"sceph9","pwl_path":"/tmp/rbd-pwl.rbd.abcdef123456.pool","pwl_size":1073741824}
Watchers:
watcher=10.10.0.102:0/1061883624 client.25496 cookie=140338056493088
Persistent cache state:
host: sceph9
path: /mnt/nvme0/rbd-pwl.rbd.101e5824ad9a.pool
size: 1 GiB
mode: ssd
stats_timestamp: Sun Apr 10 13:26:32 2022
present: true empty: false clean: false
allocated: 509 MiB
cached: 501 MiB
dirty: 338 MiB
free: 515 MiB
hits_full: 1450 / 61%
hits_partial: 0 / 0%
misses: 924
hit_bytes: 192 MiB / 66%
miss_bytes: 97 MiB

Discard Cache
-------------
Expand Down
7 changes: 0 additions & 7 deletions src/common/options/rbd.yaml.in
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
72 changes: 35 additions & 37 deletions src/librbd/cache/pwl/AbstractWriteLog.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -315,7 +315,8 @@ 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()
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
Expand All @@ -332,15 +333,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>
Expand Down Expand Up @@ -560,17 +558,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);
}

Expand All @@ -585,6 +580,19 @@ void AbstractWriteLog<I>::update_image_cache_state() {
template <typename I>
void AbstractWriteLog<I>::update_image_cache_state(Context *on_finish) {
ldout(m_image_ctx.cct, 10) << dendl;

ceph_assert(ceph_mutex_is_locked_by_me(m_lock));
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;
m_cache_state->write_image_cache_state(on_finish);
}

Expand Down Expand Up @@ -614,6 +622,7 @@ void AbstractWriteLog<I>::init(Context *on_finish) {
Context *ctx = new LambdaContext(
[this, on_finish](int r) {
if (r >= 0) {
std::lock_guard locker(m_lock);
update_image_cache_state(on_finish);
} else {
on_finish->complete(r);
Expand All @@ -633,34 +642,25 @@ void AbstractWriteLog<I>::shut_down(Context *on_finish) {

Context *ctx = new LambdaContext(
[this, on_finish](int r) {
if (m_perfcounter) {
perf_stop();
}
ldout(m_image_ctx.cct, 6) << "shutdown complete" << dendl;
m_image_ctx.op_work_queue->queue(on_finish, r);
});
ctx = new LambdaContext(
[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();
}
{
std::lock_guard locker(m_lock);
check_image_cache_state_clean();
m_wake_up_enabled = false;
m_log_entries.clear();
m_cache_state->clean = true;
m_cache_state->empty = true;

remove_pool_file();
periodic_stats();

if (m_perfcounter) {
perf_stop();
}
}
std::lock_guard locker(m_lock);
check_image_cache_state_clean();
m_wake_up_enabled = false;
m_log_entries.clear();
m_cache_state->clean = true;
m_cache_state->empty = true;
remove_pool_file();
update_image_cache_state(next_ctx);
});
ctx = new LambdaContext(
Expand All @@ -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);
});
Expand Down
2 changes: 0 additions & 2 deletions src/librbd/cache/pwl/AbstractWriteLog.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -212,8 +212,6 @@ class AbstractWriteLog {
/* 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;
Expand Down
138 changes: 67 additions & 71 deletions src/librbd/cache/pwl/ImageCacheState.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand All @@ -24,59 +23,65 @@ 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);
}
return success;
template <typename I>
void ImageCacheState<I>::init_from_config() {
ldout(m_image_ctx->cct, 20) << dendl;

present = false;
empty = true;
clean = true;
host = "";
path = "";
ConfigProxy &config = m_image_ctx->config;
mode = config.get_val<std::string>("rbd_persistent_cache_mode");
size = 0;
}
} // namespace

template <typename I>
ImageCacheState<I>::ImageCacheState(I *image_ctx, 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 config data. "
bool ImageCacheState<I>::init_from_metadata(json_spirit::mValue& json_root) {
ldout(m_image_ctx->cct, 20) << dendl;

try {
auto& o = json_root.get_obj();
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(m_image_ctx->cct) << "failed to parse cache state: " << e.what()
<< dendl;
return false;
}

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");
}

template <typename I>
ImageCacheState<I>::ImageCacheState(
I *image_ctx, JSONFormattable &f, 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");
return true;
}

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;
std::string image_state_json = json_spirit::write(o);

ldout(m_image_ctx->cct, 20) << __func__ << " Store state: "
<< image_state_json << dendl;
Expand All @@ -92,17 +97,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) {
Expand Down Expand Up @@ -133,22 +127,23 @@ ImageCacheState<I>* ImageCacheState<I>::create_image_cache_state(
r = -EINVAL;
}else if ((!dirty_cache || cache_state_str.empty()) && cache_desired) {
cache_state = new ImageCacheState<I>(image_ctx, plugin_api);
cache_state->init_from_config();
} else {
ceph_assert(!cache_state_str.empty());
JSONFormattable f;
bool success = get_json_format(cache_state_str, &f);
if (!success) {
lderr(image_ctx->cct) << "Failed to parse cache state: "
<< cache_state_str << dendl;
json_spirit::mValue json_root;
if (!json_spirit::read(cache_state_str.c_str(), json_root)) {
lderr(image_ctx->cct) << "failed to parse cache state" << dendl;
r = -EINVAL;
return nullptr;
}

bool cache_exists = (bool)f["present"];
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, plugin_api);
if (!cache_state->init_from_metadata(json_root)) {
delete cache_state;
r = -EINVAL;
return nullptr;
}
if (!cache_state->present) {
cache_state->init_from_config();
}
}
return cache_state;
Expand All @@ -162,12 +157,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);
if (!success) {
cache_state = new ImageCacheState<I>(image_ctx, plugin_api);
// ignore errors, best effort
cache_state = new ImageCacheState<I>(image_ctx, plugin_api);
json_spirit::mValue json_root;
if (!json_spirit::read(cache_state_str.c_str(), json_root)) {
lderr(image_ctx->cct) << "failed to parse cache state" << dendl;
} else {
cache_state = new ImageCacheState<I>(image_ctx, f, plugin_api);
cache_state->init_from_metadata(json_root);
}
}
return cache_state;
Expand Down
Loading

0 comments on commit 3c55687

Please sign in to comment.