RepoMirrors/ceph
1
0
Fork 0
mirror of https://github.com/ceph/ceph synced 2024-12-29 15:03:33 +00:00
Code Issues Packages Projects Releases Wiki Activity

crimson/os/seastore/lba_manager: consolidate logs

Browse Source 
Signed-off-by: Yingxin Cheng <yingxin.cheng@intel.com>
This commit is contained in:
Yingxin Cheng 2022-02-07 18:50:47 +08:00
parent 614088b684
commit 798f00e7b4
4 changed files with 112 additions and 59 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

143
src/crimson/os/seastore/lba_manager/btree/btree_lba_manager.cc
View File

@ -11,12 +11,20 @@
#include "crimson/os/seastore/logging.h"
SET_SUBSYS(seastore_lba);
/*
* levels:
* - INFO: mkfs
* - DEBUG: modification operations
* - TRACE: read operations, DEBUG details
*/
namespace crimson::os::seastore::lba_manager::btree {
BtreeLBAManager::mkfs_ret BtreeLBAManager::mkfs(
Transaction &t)
{
LOG_PREFIX(BtreeLBAManager::mkfs);
INFOT("start", t);
return cache.get_root(t).si_then([this, &t](auto croot) {
croot->get_root().lba_root = LBABtree::mkfs(get_context(t));
return mkfs_iertr::now();
@ -34,20 +42,24 @@ BtreeLBAManager::get_mappings(
laddr_t offset, extent_len_t length)
{
LOG_PREFIX(BtreeLBAManager::get_mappings);
DEBUGT("offset: {}, length{}", t, offset, length);
TRACET("{}~{}", t, offset, length);
auto c = get_context(t);
return with_btree_state<lba_pin_list_t>(
c,
[c, offset, length](auto &btree, auto &ret) {
[c, offset, length, FNAME](auto &btree, auto &ret) {
return LBABtree::iterate_repeat(
c,
btree.upper_bound_right(c, offset),
[&ret, offset, length](auto &pos) {
[&ret, offset, length, c, FNAME](auto &pos) {
if (pos.is_end() || pos.get_key() >= (offset + length)) {
TRACET("{}~{} done with {} results",
c.trans, offset, length, ret.size());
return LBABtree::iterate_repeat_ret_inner(
interruptible::ready_future_marker{},
seastar::stop_iteration::yes);
}
TRACET("{}~{} got {}, {}, repeat ...",
c.trans, offset, length, pos.get_key(), pos.get_val());
ceph_assert((pos.get_key() + pos.get_val().len) > offset);
ret.push_back(pos.get_pin());
return LBABtree::iterate_repeat_ret_inner(
@ -64,7 +76,7 @@ BtreeLBAManager::get_mappings(
laddr_list_t &&list)
{
LOG_PREFIX(BtreeLBAManager::get_mappings);
DEBUGT("{}", t, list);
TRACET("{}", t, list);
auto l = std::make_unique<laddr_list_t>(std::move(list));
auto retptr = std::make_unique<lba_pin_list_t>();
auto &ret = *retptr;
@ -88,7 +100,7 @@ BtreeLBAManager::get_mapping(
laddr_t offset)
{
LOG_PREFIX(BtreeLBAManager::get_mapping);
DEBUGT("{}", t, offset);
TRACET("{}", t, offset);
auto c = get_context(t);
return with_btree_ret<LBAPinRef>(
c,
@ -97,10 +109,12 @@ BtreeLBAManager::get_mapping(
c, offset
).si_then([FNAME, offset, c](auto iter) -> get_mapping_ret {
if (iter.is_end() || iter.get_key() != offset) {
DEBUGT("{} doesn't exist", c.trans, offset);
return crimson::ct_error::enoent::make();
} else {
TRACET("{} got {}, {}",
c.trans, offset, iter.get_key(), iter.get_val());
auto e = iter.get_pin();
DEBUGT("got mapping {}", c.trans, *e);
return get_mapping_ret(
interruptible::ready_future_marker{},
std::move(e));
@ -127,47 +141,59 @@ BtreeLBAManager::alloc_extent(
};
LOG_PREFIX(BtreeLBAManager::alloc_extent);
DEBUGT("hint: {}, length: {}", t, hint, len);
TRACET("{}~{}, hint={}", t, addr, len, hint);
auto c = get_context(t);
++stats.num_alloc_extents;
auto lookup_attempts = stats.num_alloc_extents_iter_nexts;
return with_btree_state<state_t>(
c,
hint,
[this, FNAME, c, hint, len, addr, &t](auto &btree, auto &state) {
[this, FNAME, c, hint, len, addr, lookup_attempts, &t](auto &btree, auto &state) {
return LBABtree::iterate_repeat(
c,
btree.upper_bound_right(c, hint),
[this, &state, len, &t, hint, FNAME](auto &pos) {
[this, &state, len, addr, &t, hint, FNAME, lookup_attempts](auto &pos) {
++stats.num_alloc_extents_iter_nexts;
if (!pos.is_end()) {
DEBUGT("iterate_repeat: pos: {}~{}, state: {}~{}, hint: {}",
t,
pos.get_key(),
pos.get_val().len,
if (pos.is_end()) {
DEBUGT("{}~{}, hint={}, state: end, done with {} attempts, insert at {}",
t, addr, len, hint,
stats.num_alloc_extents_iter_nexts - lookup_attempts,
state.last_end);
state.insert_iter = pos;
return LBABtree::iterate_repeat_ret_inner(
interruptible::ready_future_marker{},
seastar::stop_iteration::yes);
} else if (pos.get_key() >= (state.last_end + len)) {
DEBUGT("{}~{}, hint={}, state: {}~{}, done with {} attempts, insert at {} -- {}",
t, addr, len, hint,
pos.get_key(), pos.get_val().len,
stats.num_alloc_extents_iter_nexts - lookup_attempts,
state.last_end,
len,
hint);
}
if (pos.is_end() || pos.get_key() >= (state.last_end + len)) {
pos.get_val());
state.insert_iter = pos;
return LBABtree::iterate_repeat_ret_inner(
interruptible::ready_future_marker{},
seastar::stop_iteration::yes);
} else {
state.last_end = pos.get_key() + pos.get_val().len;
TRACET("{}~{}, hint={}, state: {}~{}, repeat ... -- {}",
t, addr, len, hint,
pos.get_key(), pos.get_val().len,
pos.get_val());
return LBABtree::iterate_repeat_ret_inner(
interruptible::ready_future_marker{},
seastar::stop_iteration::no);
}
}).si_then([FNAME, c, addr, len, &btree, &state] {
DEBUGT("about to insert at addr {}~{}", c.trans, state.last_end, len);
}).si_then([FNAME, c, addr, len, hint, &btree, &state] {
return btree.insert(
c,
*state.insert_iter,
state.last_end,
lba_map_val_t{len, addr, 1, 0}
).si_then([&state](auto &&p) {
).si_then([&state, FNAME, c, addr, len, hint](auto &&p) {
auto [iter, inserted] = std::move(p);
TRACET("{}~{}, hint={}, inserted at {}",
c.trans, addr, len, hint, state.last_end);
ceph_assert(inserted);
state.ret = iter;
});
@ -210,6 +236,7 @@ void BtreeLBAManager::complete_transaction(
Transaction &t)
{
LOG_PREFIX(BtreeLBAManager::complete_transaction);
DEBUGT("start", t);
std::vector<CachedExtentRef> to_clear;
to_clear.reserve(t.get_retired_set().size());
for (auto &e: t.get_retired_set()) {
@ -223,7 +250,7 @@ void BtreeLBAManager::complete_transaction(
for (auto &e: to_clear) {
auto &pin = get_pin(*e);
DEBUGT("retiring {}, {}", t, *e, pin);
DEBUGT("retiring extent {} -- {}", t, pin, *e);
pin_set.retire(pin);
}
@ -240,13 +267,13 @@ void BtreeLBAManager::complete_transaction(
[](auto &l, auto &r) -> bool { return get_depth(*l) > get_depth(*r); });
for (auto &e : to_link) {
DEBUGT("linking {}", t, *e);
DEBUGT("linking extent -- {}", t, *e);
pin_set.add_pin(get_pin(*e));
}
for (auto &e: to_clear) {
auto &pin = get_pin(*e);
DEBUGT("checking {}, {}", t, *e, pin);
TRACET("checking extent {} -- {}", t, pin, *e);
pin_set.check_parent(pin);
}
}
@ -256,15 +283,16 @@ BtreeLBAManager::init_cached_extent_ret BtreeLBAManager::init_cached_extent(
CachedExtentRef e)
{
LOG_PREFIX(BtreeLBAManager::init_cached_extent);
DEBUGT("extent {}", t, *e);
return seastar::do_with(bool(), [this, e, &t](bool& ret) {
TRACET("{}", t, *e);
return seastar::do_with(bool(), [this, e, FNAME, &t](bool& ret) {
auto c = get_context(t);
return with_btree(c, [c, e, &ret](auto &btree) {
return btree.init_cached_extent(c, e
).si_then([&ret](bool is_alive) {
ret = is_alive;
});
}).si_then([&ret] {
}).si_then([&ret, e, FNAME, c] {
DEBUGT("is_alive={} -- {}", c.trans, ret, *e);
return ret;
});
});
@ -306,7 +334,7 @@ BtreeLBAManager::scan_mapped_space_ret BtreeLBAManager::scan_mapped_space(
scan_mapped_space_func_t &&f)
{
LOG_PREFIX(BtreeLBAManager::scan_mapped_space);
DEBUGT("", t);
DEBUGT("start", t);
auto c = get_context(t);
return seastar::do_with(
std::move(f),
@ -339,14 +367,13 @@ BtreeLBAManager::rewrite_extent_ret BtreeLBAManager::rewrite_extent(
{
LOG_PREFIX(BtreeLBAManager::rewrite_extent);
if (extent->has_been_invalidated()) {
ERRORT("{} has been invalidated", t, *extent);
ERRORT("extent has been invalidated -- {}", t, *extent);
ceph_abort();
}
assert(!extent->has_been_invalidated());
assert(!extent->is_logical());
DEBUGT("rewriting {}", t, *extent);
if (is_lba_node(*extent)) {
DEBUGT("rewriting lba extent -- {}", t, *extent);
auto c = get_context(t);
return with_btree(
c,
@ -354,6 +381,7 @@ BtreeLBAManager::rewrite_extent_ret BtreeLBAManager::rewrite_extent(
return btree.rewrite_lba_extent(c, extent);
});
} else {
DEBUGT("skip non lba extent -- {}", t, *extent);
return rewrite_extent_iertr::now();
}
}
@ -365,6 +393,8 @@ BtreeLBAManager::update_mapping(
paddr_t prev_addr,
paddr_t addr)
{
LOG_PREFIX(BtreeLBAManager::update_mapping);
TRACET("laddr={}, paddr {} => {}", t, laddr, prev_addr, addr);
return update_mapping(
t,
laddr,
@ -375,14 +405,17 @@ BtreeLBAManager::update_mapping(
ceph_assert(in.paddr == prev_addr);
ret.paddr = addr;
return ret;
}).si_then(
[](auto) {},
update_le_mapping_iertr::pass_further{},
/* ENOENT in particular should be impossible */
crimson::ct_error::assert_all{
"Invalid error in BtreeLBAManager::rewrite_extent after update_mapping"
}
);
}
).si_then([&t, laddr, prev_addr, addr, FNAME](auto result) {
DEBUGT("laddr={}, paddr {} => {} done -- {}",
t, laddr, prev_addr, addr, result);
},
update_le_mapping_iertr::pass_further{},
/* ENOENT in particular should be impossible */
crimson::ct_error::assert_all{
"Invalid error in BtreeLBAManager::rewrite_extent after update_mapping"
}
);
}
BtreeLBAManager::get_physical_extent_if_live_ret
@ -393,6 +426,9 @@ BtreeLBAManager::get_physical_extent_if_live(
laddr_t laddr,
seastore_off_t len)
{
LOG_PREFIX(BtreeLBAManager::get_physical_extent_if_live);
DEBUGT("{}, laddr={}, paddr={}, length={}",
t, type, laddr, addr, len);
ceph_assert(is_lba_node(type));
auto c = get_context(t);
return with_btree_ret<CachedExtentRef>(
@ -418,6 +454,8 @@ BtreeLBAManager::BtreeLBAManager(
void BtreeLBAManager::register_metrics()
{
LOG_PREFIX(BtreeLBAManager::register_metrics);
DEBUG("start");
stats = {};
namespace sm = seastar::metrics;
metrics.add_group(
@ -443,7 +481,7 @@ BtreeLBAManager::update_refcount_ret BtreeLBAManager::update_refcount(
int delta)
{
LOG_PREFIX(BtreeLBAManager::update_refcount);
DEBUGT("addr {}, delta {}", t, addr, delta);
TRACET("laddr={}, delta={}", t, addr, delta);
return update_mapping(
t,
addr,
@ -452,13 +490,15 @@ BtreeLBAManager::update_refcount_ret BtreeLBAManager::update_refcount(
ceph_assert((int)out.refcount + delta >= 0);
out.refcount += delta;
return out;
}).si_then([](auto result) {
return ref_update_result_t{
result.refcount,
result.paddr,
result.len
};
});
}
).si_then([&t, addr, delta, FNAME](auto result) {
DEBUGT("laddr={}, delta={} done -- {}", t, addr, delta, result);
return ref_update_result_t{
result.refcount,
result.paddr,
result.len
};
});
}
BtreeLBAManager::update_mapping_ret BtreeLBAManager::update_mapping(
@ -466,8 +506,6 @@ BtreeLBAManager::update_mapping_ret BtreeLBAManager::update_mapping(
laddr_t addr,
update_func_t &&f)
{
LOG_PREFIX(BtreeLBAManager::update_mapping);
DEBUGT("addr {}", t, addr);
auto c = get_context(t);
return with_btree_ret<lba_map_val_t>(
c,
@ -477,6 +515,8 @@ BtreeLBAManager::update_mapping_ret BtreeLBAManager::update_mapping(
).si_then([&btree, f=std::move(f), c, addr](auto iter)
-> update_mapping_ret {
if (iter.is_end() || iter.get_key() != addr) {
LOG_PREFIX(BtreeLBAManager::update_mapping);
DEBUGT("laddr={} doesn't exist", c.trans, addr);
return crimson::ct_error::enoent::make();
}
@ -505,7 +545,8 @@ BtreeLBAManager::~BtreeLBAManager()
{
pin_set.scan([](auto &i) {
LOG_PREFIX(BtreeLBAManager::~BtreeLBAManager);
ERROR("Found {} {} has_ref={}", i, i.get_extent(), i.has_ref());
ERROR("Found {}, has_ref={} -- {}",
i, i.has_ref(), i.get_extent());
});
}

12
src/crimson/os/seastore/lba_manager/btree/btree_range_pin.cc
View File

@ -29,7 +29,7 @@ btree_range_pin_t::~btree_range_pin_t()
ceph_assert(!pins == !is_linked());
ceph_assert(!ref);
if (pins) {
DEBUG("removing {}", *this);
TRACE("removing {}", *this);
pins->remove_pin(*this, true);
}
extent = nullptr;
@ -43,7 +43,7 @@ void btree_pin_set_t::replace_pin(btree_range_pin_t &to, btree_range_pin_t &from
void btree_pin_set_t::remove_pin(btree_range_pin_t &pin, bool do_check_parent)
{
LOG_PREFIX(btree_pin_set_t::remove_pin);
DEBUG("{}", pin);
TRACE("{}", pin);
ceph_assert(pin.is_linked());
ceph_assert(pin.pins);
ceph_assert(!pin.ref);
@ -124,14 +124,14 @@ void btree_pin_set_t::add_pin(btree_range_pin_t &pin)
auto *parent = maybe_get_parent(pin.range);
ceph_assert(parent);
if (!parent->has_ref()) {
DEBUG("acquiring parent {}", static_cast<void*>(parent));
TRACE("acquiring parent {}", static_cast<void*>(parent));
parent->acquire_ref();
} else {
DEBUG("parent has ref {}", static_cast<void*>(parent));
TRACE("parent has ref {}", static_cast<void*>(parent));
}
}
if (maybe_get_first_child(pin.range) != nullptr) {
DEBUG("acquiring self {}", pin);
TRACE("acquiring self {}", pin);
pin.acquire_ref();
}
}
@ -147,7 +147,7 @@ void btree_pin_set_t::check_parent(btree_range_pin_t &pin)
LOG_PREFIX(btree_pin_set_t::check_parent);
auto parent = maybe_get_parent(pin.range);
if (parent) {
DEBUG("releasing parent {}", *parent);
TRACE("releasing parent {}", *parent);
release_if_no_children(*parent);
}
}

14
src/crimson/os/seastore/lba_manager/btree/lba_btree_node.cc
View File

@ -17,6 +17,16 @@ SET_SUBSYS(seastore_lba);
namespace crimson::os::seastore::lba_manager::btree {
std::ostream& operator<<(std::ostream& out, const lba_map_val_t& v)
{
return out << "lba_map_val_t("
<< v.paddr
<< "~" << v.len
<< ", refcount=" << v.refcount
<< ", checksum=" << v.checksum
<< ")";
}
std::ostream &LBAInternalNode::print_detail(std::ostream &out) const
{
return out << ", size=" << get_size()
@ -29,7 +39,7 @@ void LBAInternalNode::resolve_relative_addrs(paddr_t base)
for (auto i: *this) {
if (i->get_val().is_relative()) {
auto updated = base.add_relative(i->get_val());
DEBUG("{} -> {}", i->get_val(), updated);
TRACE("{} -> {}", i->get_val(), updated);
i->set_val(updated);
}
}
@ -48,7 +58,7 @@ void LBALeafNode::resolve_relative_addrs(paddr_t base)
if (i->get_val().paddr.is_relative()) {
auto val = i->get_val();
val.paddr = base.add_relative(val.paddr);
DEBUG("{} -> {}", i->get_val().paddr, val.paddr);
TRACE("{} -> {}", i->get_val().paddr, val.paddr);
i->set_val(val);
}
}

2
src/crimson/os/seastore/lba_manager/btree/lba_btree_node.h
View File

@ -55,6 +55,8 @@ WRITE_EQ_OPERATORS_4(
refcount,
checksum);
std::ostream& operator<<(std::ostream& out, const lba_map_val_t&);
class BtreeLBAPin;
using BtreeLBAPinRef = std::unique_ptr<BtreeLBAPin>;