From b495938d1830725674403f8399f2d6419d150995 Mon Sep 17 00:00:00 2001 From: Yingxin Cheng Date: Mon, 22 Nov 2021 16:55:02 +0800 Subject: [PATCH] crimson/os/seastore: add debug logs to print transaction name Signed-off-by: Yingxin Cheng --- src/crimson/os/seastore/cache.h | 29 +++---------- src/crimson/os/seastore/seastore.cc | 42 +++++++++++++------ src/crimson/os/seastore/seastore.h | 17 +++++--- src/crimson/os/seastore/segment_cleaner.cc | 11 +++-- src/crimson/os/seastore/segment_cleaner.h | 10 +++-- .../os/seastore/transaction_manager.cc | 8 +++- src/crimson/os/seastore/transaction_manager.h | 10 +++-- src/crimson/tools/store_nbd/tm_driver.cc | 12 ++++-- .../seastore/test_btree_lba_manager.cc | 15 ++++--- .../crimson/seastore/test_seastore_cache.cc | 3 +- .../seastore/transaction_manager_test_state.h | 9 ++-- 11 files changed, 100 insertions(+), 66 deletions(-) diff --git a/src/crimson/os/seastore/cache.h b/src/crimson/os/seastore/cache.h index 81908a42f9fd1..a1a442fa25d53 100644 --- a/src/crimson/os/seastore/cache.h +++ b/src/crimson/os/seastore/cache.h @@ -95,41 +95,24 @@ public: /// Creates empty transaction by source TransactionRef create_transaction( - Transaction::src_t src) { + Transaction::src_t src, + const char* name, + bool is_weak) { LOG_PREFIX(Cache::create_transaction); ++(get_by_src(stats.trans_created_by_src, src)); auto ret = std::make_unique( get_dummy_ordering_handle(), - false, - src, - last_commit, - [this](Transaction& t) { - return on_transaction_destruct(t); - } - ); - DEBUGT("created source={}", *ret, src); - return ret; - } - - /// Creates empty weak transaction by source - TransactionRef create_weak_transaction( - Transaction::src_t src) { - LOG_PREFIX(Cache::create_weak_transaction); - - ++(get_by_src(stats.trans_created_by_src, src)); - - auto ret = std::make_unique( - get_dummy_ordering_handle(), - true, + is_weak, src, last_commit, [this](Transaction& t) { return on_transaction_destruct(t); } ); - DEBUGT("created source={}", *ret, src); + DEBUGT("created name={}, source={}, is_weak={}", + *ret, name, src, is_weak); return ret; } diff --git a/src/crimson/os/seastore/seastore.cc b/src/crimson/os/seastore/seastore.cc index 8bfb705d1d54f..600ba4b58f77a 100644 --- a/src/crimson/os/seastore/seastore.cc +++ b/src/crimson/os/seastore/seastore.cc @@ -299,7 +299,10 @@ SeaStore::mkfs_ertr::future<> SeaStore::mkfs(uuid_d new_osd_fsid) }).safe_then([this] { return repeat_eagain([this] { return transaction_manager->with_transaction_intr( - Transaction::src_t::MUTATE, [this](auto& t) { + Transaction::src_t::MUTATE, + "mkfs_seastore", + [this](auto& t) + { return onode_manager->mkfs(t ).si_then([this, &t] { return collection_manager->mkfs(t); @@ -359,8 +362,10 @@ SeaStore::list_objects(CollectionRef ch, [this, start, end, limit] (auto& ret) { return repeat_eagain([this, start, end, limit, &ret] { return transaction_manager->with_transaction_intr( - Transaction::src_t::READ, - [this, start, end, limit](auto &t) { + Transaction::src_t::READ, + "list_objects", + [this, start, end, limit](auto &t) + { return onode_manager->list_onodes(t, start, end, limit); }).safe_then([&ret](auto&& _ret) { ret = std::move(_ret); @@ -403,8 +408,10 @@ seastar::future> SeaStore::list_collections() [this](auto &ret) { return repeat_eagain([this, &ret] { return transaction_manager->with_transaction_intr( - Transaction::src_t::READ, - [this, &ret](auto& t) { + Transaction::src_t::READ, + "list_collections", + [this, &ret](auto& t) + { return transaction_manager->read_collection_root(t ).si_then([this, &t](auto coll_root) { return collection_manager->list(coll_root, t); @@ -439,6 +446,7 @@ SeaStore::read_errorator::future SeaStore::read( ch, oid, Transaction::src_t::READ, + "read_obj", op_type_t::READ, [=](auto &t, auto &onode) -> ObjectDataHandler::read_ret { size_t size = onode.get_layout().size; @@ -485,6 +493,7 @@ SeaStore::get_attr_errorator::future SeaStore::get_attr( c, oid, Transaction::src_t::READ, + "get_attr", op_type_t::GET_ATTR, [=](auto &t, auto& onode) -> _omap_get_value_ret { auto& layout = onode.get_layout(); @@ -520,6 +529,7 @@ SeaStore::get_attrs_ertr::future SeaStore::get_attrs( c, oid, Transaction::src_t::READ, + "get_addrs", op_type_t::GET_ATTRS, [=](auto &t, auto& onode) { auto& layout = onode.get_layout(); @@ -555,6 +565,7 @@ seastar::future SeaStore::stat( c, oid, Transaction::src_t::READ, + "stat", op_type_t::STAT, [=, &oid](auto &t, auto &onode) { struct stat st; @@ -593,6 +604,7 @@ SeaStore::omap_get_values( c, oid, Transaction::src_t::READ, + "omap_get_values", op_type_t::OMAP_GET_VALUES, [this, keys](auto &t, auto &onode) { omap_root_t omap_root = onode.get_layout().omap_root.get(onode.get_hint()); @@ -702,6 +714,7 @@ SeaStore::omap_get_values_ret_t SeaStore::omap_list( c, oid, Transaction::src_t::READ, + "omap_list", op_type_t::OMAP_LIST, [this, config, &start](auto &t, auto &onode) { return _omap_list( @@ -860,6 +873,7 @@ seastar::future<> SeaStore::do_transaction( _ch, std::move(_t), Transaction::src_t::MUTATE, + "do_transaction", op_type_t::TRANSACTION, [this](auto &ctx) { return with_trans_intr(*ctx.transaction, [&, this](auto &t) { @@ -1322,14 +1336,16 @@ seastar::future<> SeaStore::write_meta(const std::string& key, return repeat_eagain([this, FNAME, &key, &value] { return transaction_manager->with_transaction_intr( Transaction::src_t::MUTATE, - [this, FNAME, &key, &value](auto& t) { - DEBUGT("Have transaction, key: {}; value: {}", t, key, value); - return transaction_manager->update_root_meta( - t, key, value - ).si_then([this, &t] { - return transaction_manager->submit_transaction(t); - }); - }); + "write_meta", + [this, FNAME, &key, &value](auto& t) + { + DEBUGT("Have transaction, key: {}; value: {}", t, key, value); + return transaction_manager->update_root_meta( + t, key, value + ).si_then([this, &t] { + return transaction_manager->submit_transaction(t); + }); + }); }).safe_then([this, &key, &value] { return mdstore->write_meta(key, value); }); diff --git a/src/crimson/os/seastore/seastore.h b/src/crimson/os/seastore/seastore.h index 8e508c6a3f274..b205872141d79 100644 --- a/src/crimson/os/seastore/seastore.h +++ b/src/crimson/os/seastore/seastore.h @@ -201,12 +201,13 @@ private: CollectionRef ch, ceph::os::Transaction &&t, Transaction::src_t src, + const char* tname, op_type_t op_type, F &&f) { return seastar::do_with( internal_context_t( ch, std::move(t), - transaction_manager->create_transaction(src)), + transaction_manager->create_transaction(src, tname)), std::forward(f), [this, op_type](auto &ctx, auto &f) { return ctx.transaction->get_handle().take_collection_lock( @@ -234,15 +235,21 @@ private: CollectionRef ch, const ghobject_t &oid, Transaction::src_t src, + const char* tname, op_type_t op_type, F &&f) const { auto begin_time = std::chrono::steady_clock::now(); return seastar::do_with( - oid, Ret{}, OnodeRef(), std::forward(f), - [this, src, op_type, begin_time](auto &oid, auto &ret, auto &onode, auto &f) { - return repeat_eagain([&, this, src] { + oid, Ret{}, OnodeRef(), std::forward(f), + [this, src, op_type, begin_time, tname + ](auto &oid, auto &ret, auto &onode, auto &f) + { + return repeat_eagain([&, this, src, tname] { return transaction_manager->with_transaction_intr( - src, [&, this](auto& t) { + src, + tname, + [&, this](auto& t) + { return onode_manager->get_onode(t, oid ).si_then([&](auto onode_ret) { onode = std::move(onode_ret); diff --git a/src/crimson/os/seastore/segment_cleaner.cc b/src/crimson/os/seastore/segment_cleaner.cc index af3fdefcf1edc..615040e94d32e 100644 --- a/src/crimson/os/seastore/segment_cleaner.cc +++ b/src/crimson/os/seastore/segment_cleaner.cc @@ -309,7 +309,10 @@ SegmentCleaner::gc_trim_journal_ret SegmentCleaner::gc_trim_journal() { return repeat_eagain([this] { return ecb->with_transaction_intr( - Transaction::src_t::CLEANER_TRIM, [this](auto& t) { + Transaction::src_t::CLEANER_TRIM, + "trim_journal", + [this](auto& t) + { return rewrite_dirty(t, get_dirty_tail() ).si_then([this, &t] { return ecb->submit_transaction_direct(t); @@ -349,8 +352,10 @@ SegmentCleaner::gc_reclaim_space_ret SegmentCleaner::gc_reclaim_space() "SegmentCleaner::gc_reclaim_space: processing {} extents", extents.size()); return ecb->with_transaction_intr( - Transaction::src_t::CLEANER_RECLAIM, - [this, &extents](auto& t) { + Transaction::src_t::CLEANER_RECLAIM, + "reclaim_space", + [this, &extents](auto& t) + { return trans_intr::do_for_each( extents, [this, &t](auto &extent) { diff --git a/src/crimson/os/seastore/segment_cleaner.h b/src/crimson/os/seastore/segment_cleaner.h index ef7fb731d7ef0..b9bf9d9cb336c 100644 --- a/src/crimson/os/seastore/segment_cleaner.h +++ b/src/crimson/os/seastore/segment_cleaner.h @@ -472,13 +472,17 @@ public: public: virtual ~ExtentCallbackInterface() = default; - virtual TransactionRef create_transaction(Transaction::src_t) = 0; + virtual TransactionRef create_transaction( + Transaction::src_t, const char*) = 0; /// Creates empty transaction with interruptible context template - auto with_transaction_intr(Transaction::src_t src, Func &&f) { + auto with_transaction_intr( + Transaction::src_t src, + const char* name, + Func &&f) { return seastar::do_with( - create_transaction(src), + create_transaction(src, name), [f=std::forward(f)](auto &ref_t) mutable { return with_trans_intr( *ref_t, diff --git a/src/crimson/os/seastore/transaction_manager.cc b/src/crimson/os/seastore/transaction_manager.cc index 08527ff8ec3bb..011bd1766490b 100644 --- a/src/crimson/os/seastore/transaction_manager.cc +++ b/src/crimson/os/seastore/transaction_manager.cc @@ -42,7 +42,10 @@ TransactionManager::mkfs_ertr::future<> TransactionManager::mkfs() DEBUG("about to do_with"); segment_cleaner->init_mkfs(addr); return with_transaction_intr( - Transaction::src_t::MUTATE, [this, FNAME](auto& t) { + Transaction::src_t::MUTATE, + "mkfs_tm", + [this, FNAME](auto& t) + { DEBUGT("about to cache->mkfs", t); cache->init(); return cache->mkfs(t @@ -89,7 +92,8 @@ TransactionManager::mount_ertr::future<> TransactionManager::mount() }).safe_then([this, FNAME](auto addr) { segment_cleaner->set_journal_head(addr); return seastar::do_with( - create_weak_transaction(Transaction::src_t::READ), + create_weak_transaction( + Transaction::src_t::READ, "mount"), [this, FNAME](auto &tref) { return with_trans_intr( *tref, diff --git a/src/crimson/os/seastore/transaction_manager.h b/src/crimson/os/seastore/transaction_manager.h index eede86737a629..e3f04b3b38d43 100644 --- a/src/crimson/os/seastore/transaction_manager.h +++ b/src/crimson/os/seastore/transaction_manager.h @@ -88,14 +88,16 @@ public: /// Creates empty transaction TransactionRef create_transaction( - Transaction::src_t src) final { - return cache->create_transaction(src); + Transaction::src_t src, + const char* name) final { + return cache->create_transaction(src, name, false); } /// Creates empty weak transaction TransactionRef create_weak_transaction( - Transaction::src_t src) { - return cache->create_weak_transaction(src); + Transaction::src_t src, + const char* name) { + return cache->create_transaction(src, name, true); } /// Resets transaction diff --git a/src/crimson/tools/store_nbd/tm_driver.cc b/src/crimson/tools/store_nbd/tm_driver.cc index dad672044289f..19cbd56e5e629 100644 --- a/src/crimson/tools/store_nbd/tm_driver.cc +++ b/src/crimson/tools/store_nbd/tm_driver.cc @@ -24,8 +24,10 @@ seastar::future<> TMDriver::write( return seastar::do_with(ptr, [this, offset](auto& ptr) { return repeat_eagain([this, offset, &ptr] { return tm->with_transaction_intr( - Transaction::src_t::MUTATE, - [this, offset, &ptr](auto& t) { + Transaction::src_t::MUTATE, + "write", + [this, offset, &ptr](auto& t) + { return tm->dec_ref(t, offset ).si_then([](auto){}).handle_error_interruptible( crimson::ct_error::enoent::handle([](auto) { return seastar::now(); }), @@ -97,8 +99,10 @@ seastar::future TMDriver::read( auto &blret = *blptrret; return repeat_eagain([=, &blret] { return tm->with_transaction_intr( - Transaction::src_t::READ, - [=, &blret](auto& t) { + Transaction::src_t::READ, + "read", + [=, &blret](auto& t) + { return read_extents(t, offset, size ).si_then([=, &blret](auto ext_list) { size_t cur = offset; diff --git a/src/test/crimson/seastore/test_btree_lba_manager.cc b/src/test/crimson/seastore/test_btree_lba_manager.cc index 9bfa40e4f3955..f54bac24506da 100644 --- a/src/test/crimson/seastore/test_btree_lba_manager.cc +++ b/src/test/crimson/seastore/test_btree_lba_manager.cc @@ -85,7 +85,8 @@ struct btree_test_base : return journal->open_for_write(); }).safe_then([this](auto addr) { return seastar::do_with( - cache->create_transaction(Transaction::src_t::MUTATE), + cache->create_transaction( + Transaction::src_t::MUTATE, "test_set_up_fut", false), [this](auto &ref_t) { return with_trans_intr(*ref_t, [&](auto &t) { cache->init(); @@ -152,7 +153,8 @@ struct lba_btree_test : btree_test_base { template auto lba_btree_update(F &&f) { - auto tref = cache->create_transaction(Transaction::src_t::MUTATE); + auto tref = cache->create_transaction( + Transaction::src_t::MUTATE, "test_btree_update", false); auto &t = *tref; with_trans_intr( t, @@ -178,7 +180,8 @@ struct lba_btree_test : btree_test_base { template auto lba_btree_read(F &&f) { - auto t = cache->create_transaction(Transaction::src_t::READ); + auto t = cache->create_transaction( + Transaction::src_t::READ, "test_btree_read", false); return with_trans_intr( *t, [this, f=std::forward(f)](auto &t) mutable { @@ -303,7 +306,8 @@ struct btree_lba_manager_test : btree_test_base { auto create_transaction(bool create_fake_extent=true) { auto t = test_transaction_t{ - cache->create_transaction(Transaction::src_t::MUTATE), + cache->create_transaction( + Transaction::src_t::MUTATE, "test_mutate_lba", false), test_lba_mappings }; if (create_fake_extent) { @@ -314,7 +318,8 @@ struct btree_lba_manager_test : btree_test_base { auto create_weak_transaction() { auto t = test_transaction_t{ - cache->create_weak_transaction(Transaction::src_t::READ), + cache->create_transaction( + Transaction::src_t::READ, "test_read_weak", true), test_lba_mappings }; return t; diff --git a/src/test/crimson/seastore/test_seastore_cache.cc b/src/test/crimson/seastore/test_seastore_cache.cc index a55bb4287b5a3..0bb8213786baa 100644 --- a/src/test/crimson/seastore/test_seastore_cache.cc +++ b/src/test/crimson/seastore/test_seastore_cache.cc @@ -67,7 +67,8 @@ struct cache_test_t : public seastar_test_suite_t { } auto get_transaction() { - return cache->create_transaction(Transaction::src_t::MUTATE); + return cache->create_transaction( + Transaction::src_t::MUTATE, "test_cache", false); } template diff --git a/src/test/crimson/seastore/transaction_manager_test_state.h b/src/test/crimson/seastore/transaction_manager_test_state.h index 003966e13d427..6323f72729efc 100644 --- a/src/test/crimson/seastore/transaction_manager_test_state.h +++ b/src/test/crimson/seastore/transaction_manager_test_state.h @@ -167,15 +167,18 @@ protected: } auto create_mutate_transaction() { - return tm->create_transaction(Transaction::src_t::MUTATE); + return tm->create_transaction( + Transaction::src_t::MUTATE, "test_mutate"); } auto create_read_transaction() { - return tm->create_transaction(Transaction::src_t::READ); + return tm->create_transaction( + Transaction::src_t::READ, "test_read"); } auto create_weak_transaction() { - return tm->create_weak_transaction(Transaction::src_t::READ); + return tm->create_weak_transaction( + Transaction::src_t::READ, "test_read_weak"); } auto submit_transaction_fut2(Transaction& t) { -- 2.39.5