From aec25bffb322fc7744c294c02e400b8c2d7cd1dd Mon Sep 17 00:00:00 2001 From: Yingxin Cheng Date: Mon, 25 Jul 2022 13:22:32 +0800 Subject: [PATCH] crimson/os/seastore: improve logs Signed-off-by: Yingxin Cheng --- src/crimson/os/seastore/cache.cc | 13 +++++++++---- src/crimson/os/seastore/cache.h | 10 ++++++---- .../os/seastore/journal/segmented_journal.cc | 6 ++++-- .../seastore/lba_manager/btree/btree_lba_manager.cc | 4 ++-- src/crimson/os/seastore/seastore_types.cc | 8 ++++++++ src/crimson/os/seastore/seastore_types.h | 2 ++ 6 files changed, 31 insertions(+), 12 deletions(-) diff --git a/src/crimson/os/seastore/cache.cc b/src/crimson/os/seastore/cache.cc index 1093180203295..c889861ffe3e9 100644 --- a/src/crimson/os/seastore/cache.cc +++ b/src/crimson/os/seastore/cache.cc @@ -1253,6 +1253,7 @@ record_t Cache::prepare_record( get_oldest_backref_dirty_from().value_or(JOURNAL_SEQ_NULL), get_oldest_dirty_from().value_or(JOURNAL_SEQ_NULL) }; + SUBDEBUGT(seastore_t, "update tails as delta {}", t, tails); bufferlist bl; encode(tails, bl); delta_info_t delta; @@ -1284,11 +1285,13 @@ record_t Cache::prepare_record( } SUBDEBUGT(seastore_t, - "commit H{} dirty_from={}, {} read, {} fresh with {} invalid, " + "commit H{} dirty_from={}, alloc_from={}, " + "{} read, {} fresh with {} invalid, " "{} delta, {} retire, {}(md={}B, data={}B) ool-records, " "{}B md, {}B data, modify_time={}", t, (void*)&t.get_handle(), get_oldest_dirty_from().value_or(JOURNAL_SEQ_NULL), + get_oldest_backref_dirty_from().value_or(JOURNAL_SEQ_NULL), read_stat, fresh_stat, fresh_invalid_stat, @@ -1360,7 +1363,7 @@ void Cache::backref_batch_update( const journal_seq_t &seq) { LOG_PREFIX(Cache::backref_batch_update); - DEBUG("inserting {} entries", list.size()); + DEBUG("inserting {} entries at {}", list.size(), seq); if (!backref_buffer) { backref_buffer = std::make_unique(); } @@ -1571,10 +1574,12 @@ Cache::mkfs_iertr::future<> Cache::mkfs(Transaction &t) Cache::close_ertr::future<> Cache::close() { LOG_PREFIX(Cache::close); - INFO("close with {}({}B) dirty from {}, {}({}B) lru, totally {}({}B) indexed extents", + INFO("close with {}({}B) dirty, dirty_from={}, alloc_from={}, " + "{}({}B) lru, totally {}({}B) indexed extents", dirty.size(), stats.dirty_bytes, get_oldest_dirty_from().value_or(JOURNAL_SEQ_NULL), + get_oldest_backref_dirty_from().value_or(JOURNAL_SEQ_NULL), lru.get_current_contents_extents(), lru.get_current_contents_bytes(), extents.size(), @@ -1647,7 +1652,7 @@ Cache::replay_delta( // replay dirty if (journal_seq < dirty_tail) { DEBUG("journal_seq {} < dirty_tail {}, don't replay {}", - journal_seq, alloc_tail, delta); + journal_seq, dirty_tail, delta); return replay_delta_ertr::now(); } diff --git a/src/crimson/os/seastore/cache.h b/src/crimson/os/seastore/cache.h index e763264d41dcd..99dc301df99d0 100644 --- a/src/crimson/os/seastore/cache.h +++ b/src/crimson/os/seastore/cache.h @@ -783,12 +783,13 @@ public: { LOG_PREFIX(Cache::init_cached_extents); SUBINFOT(seastore_cache, - "start with {}({}B) extents, {} dirty, from {}", + "start with {}({}B) extents, {} dirty, dirty_from={}, alloc_from={}", t, extents.size(), extents.get_bytes(), dirty.size(), - get_oldest_dirty_from().value_or(JOURNAL_SEQ_NULL)); + get_oldest_dirty_from().value_or(JOURNAL_SEQ_NULL), + get_oldest_backref_dirty_from().value_or(JOURNAL_SEQ_NULL)); // journal replay should has been finished at this point, // Cache::root should have been inserted to the dirty list @@ -824,12 +825,13 @@ public: } ).si_then([this, FNAME, &t] { SUBINFOT(seastore_cache, - "finish with {}({}B) extents, {} dirty, from {}", + "finish with {}({}B) extents, {} dirty, dirty_from={}, alloc_from={}", t, extents.size(), extents.get_bytes(), dirty.size(), - get_oldest_dirty_from().value_or(JOURNAL_SEQ_NULL)); + get_oldest_dirty_from().value_or(JOURNAL_SEQ_NULL), + get_oldest_backref_dirty_from().value_or(JOURNAL_SEQ_NULL)); }); } diff --git a/src/crimson/os/seastore/journal/segmented_journal.cc b/src/crimson/os/seastore/journal/segmented_journal.cc index a8b3c043a6fde..3e32ada9eb13b 100644 --- a/src/crimson/os/seastore/journal/segmented_journal.cc +++ b/src/crimson/os/seastore/journal/segmented_journal.cc @@ -197,11 +197,13 @@ SegmentedJournal::scan_last_segment( found_delta = true; journal_tail_delta_t tail_delta; decode(tail_delta, delta.bl); + auto start_seq = locator.write_result.start_seq; + INFO("got {}, at seq {}", tail_delta, start_seq); if (tail_delta.alloc_tail == JOURNAL_SEQ_NULL) { - tail_delta.alloc_tail = locator.write_result.start_seq; + tail_delta.alloc_tail = start_seq; } if (tail_delta.dirty_tail == JOURNAL_SEQ_NULL) { - tail_delta.dirty_tail = locator.write_result.start_seq; + tail_delta.dirty_tail = start_seq; } segment_provider.update_journal_tails( tail_delta.dirty_tail, tail_delta.alloc_tail); diff --git a/src/crimson/os/seastore/lba_manager/btree/btree_lba_manager.cc b/src/crimson/os/seastore/lba_manager/btree/btree_lba_manager.cc index 502978f6bc4df..7b173a23f0f11 100644 --- a/src/crimson/os/seastore/lba_manager/btree/btree_lba_manager.cc +++ b/src/crimson/os/seastore/lba_manager/btree/btree_lba_manager.cc @@ -128,7 +128,7 @@ 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); + ERRORT("laddr={} doesn't exist", c.trans, offset); return crimson::ct_error::enoent::make(); } else { TRACET("{} got {}, {}", @@ -526,7 +526,7 @@ BtreeLBAManager::_update_mapping_ret BtreeLBAManager::_update_mapping( -> _update_mapping_ret { if (iter.is_end() || iter.get_key() != addr) { LOG_PREFIX(BtreeLBAManager::_update_mapping); - DEBUGT("laddr={} doesn't exist", c.trans, addr); + ERRORT("laddr={} doesn't exist", c.trans, addr); return crimson::ct_error::enoent::make(); } diff --git a/src/crimson/os/seastore/seastore_types.cc b/src/crimson/os/seastore/seastore_types.cc index 21f7e547efda3..72ab3b81f051a 100644 --- a/src/crimson/os/seastore/seastore_types.cc +++ b/src/crimson/os/seastore/seastore_types.cc @@ -255,6 +255,14 @@ std::ostream &operator<<(std::ostream &out, const delta_info_t &delta) << ")"; } +std::ostream &operator<<(std::ostream &out, const journal_tail_delta_t &delta) +{ + return out << "journal_tail_delta_t(" + << "alloc_tail=" << delta.alloc_tail + << ", dirty_tail=" << delta.dirty_tail + << ")"; +} + std::ostream &operator<<(std::ostream &out, const extent_info_t &info) { return out << "extent_info_t(" diff --git a/src/crimson/os/seastore/seastore_types.h b/src/crimson/os/seastore/seastore_types.h index a745f29e30d24..a7849b0a20e66 100644 --- a/src/crimson/os/seastore/seastore_types.h +++ b/src/crimson/os/seastore/seastore_types.h @@ -1120,6 +1120,8 @@ struct journal_tail_delta_t { } }; +std::ostream &operator<<(std::ostream &out, const journal_tail_delta_t &delta); + class object_data_t { laddr_t reserved_data_base = L_ADDR_NULL; extent_len_t reserved_data_len = 0; -- 2.39.5