From: Xuehan Xu Date: Sat, 23 May 2026 05:00:55 +0000 (+0800) Subject: debug X-Git-Url: http://git-server-git.apps.pok.os.sepia.ceph.com/?a=commitdiff_plain;h=65188736e8b31640cd6ccbe0183833ee2bc0f5af;p=ceph-ci.git debug --- diff --git a/src/crimson/os/seastore/backref/btree_backref_manager.cc b/src/crimson/os/seastore/backref/btree_backref_manager.cc index 505ed21790d..d818d02ac49 100644 --- a/src/crimson/os/seastore/backref/btree_backref_manager.cc +++ b/src/crimson/os/seastore/backref/btree_backref_manager.cc @@ -473,22 +473,22 @@ BtreeBackrefManager::scan_device( auto bentry = cache.get_cached_backref_entry(key); if (bentry) { assert(bentry->paddr == key); - DEBUGT("found in cache: {} {}", t, bentry->paddr, bentry->laddr); + INFOT("found in cache: {} {}", t, bentry->paddr, bentry->laddr); } if (bentry && bentry->laddr == L_ADDR_NULL) { - DEBUGT("{} is removed", t, bentry->paddr); + INFOT("{} is removed", t, bentry->paddr); iter = co_await iter.next(c); continue; } if (key.get_device_id() == paddr.get_device_id()) { auto val = iter.get_val(); if (bentry && bentry->laddr != val.laddr) { - DEBUGT("{} changed from {} to {}", + INFOT("{} changed from {} to {}", t, bentry->paddr, val.laddr, bentry->laddr); iter = co_await iter.next(c); continue; } - DEBUGT("scanned {}, {}", t, key, val.laddr); + INFOT("scanned {}, {}", t, key, val.laddr); auto ret = co_await f(key, val.len, val.type, val.laddr); if (ret == seastar::stop_iteration::yes) { break; diff --git a/src/crimson/os/seastore/cache.cc b/src/crimson/os/seastore/cache.cc index fc0fb45dc72..5918996747b 100644 --- a/src/crimson/os/seastore/cache.cc +++ b/src/crimson/os/seastore/cache.cc @@ -1877,6 +1877,10 @@ record_t Cache::prepare_record( continue; } + DEBUGT("backref_entry alloc existing {}~0x{:x}", + t, + i->get_paddr(), + i->get_length()); // Note: commit extents and backref allocations in the same place // Note: remapping is split into 2 steps, retire and alloc, they must be // committed atomically together diff --git a/src/crimson/os/seastore/extent_pinboard.cc b/src/crimson/os/seastore/extent_pinboard.cc index 7c5df07bf97..2c0b170a817 100644 --- a/src/crimson/os/seastore/extent_pinboard.cc +++ b/src/crimson/os/seastore/extent_pinboard.cc @@ -322,6 +322,8 @@ public: } void add_extent(CachedExtent &extent) { + LOG_PREFIX(ExtentPromoter::add_extent); + INFO("{} current_contents: 0x{:x}", extent, current_contents); assert(!extent.is_linked_to_list()); assert(extent.is_stable_clean()); extent.set_pin_state(extent_pin_state_t::PendingPromote); @@ -329,6 +331,7 @@ public: current_contents += extent.get_length(); intrusive_ptr_add_ref(&extent); while (current_contents > promotion_size) { + INFO("removing front {}", list.front()); remove_extent(list.front(), extent_pin_state_t::Fresh); } if (should_run_promote()) { @@ -338,6 +341,8 @@ public: } void remove_extent(CachedExtent &extent, extent_pin_state_t new_state) { + LOG_PREFIX(ExtentPromoter::remove_extent); + INFO("{} {} curent_contents: 0x{:x}", extent, new_state, current_contents); assert(extent.is_linked_to_list()); assert(extent.get_pin_state() == extent_pin_state_t::PendingPromote); assert(current_contents >= extent.get_length()); @@ -358,7 +363,7 @@ public: LOG_PREFIX(ExtentPromoter::run_promote); std::size_t promote_size = 0; std::list extents; - DEBUGT("start promote", t); + INFOT("start promote", t); if (current_contents < promotion_size && test_workload) { auto id = epm.get_cold_device_id(); paddr_t start = P_ADDR_NULL; diff --git a/src/crimson/os/seastore/extent_placement_manager.cc b/src/crimson/os/seastore/extent_placement_manager.cc index 9bc1e80e122..46f5d13d65d 100644 --- a/src/crimson/os/seastore/extent_placement_manager.cc +++ b/src/crimson/os/seastore/extent_placement_manager.cc @@ -214,7 +214,7 @@ void ExtentPlacementManager::init( if (cold_cleaner) { dynamic_max_rewrite_generation = hot_tier_generations + cold_tier_generations - 1; } - DEBUG("dynamic_max_rewrite_generation: {}, " + INFO("dynamic_max_rewrite_generation: {}, " "hot_tier_generations{} , cold_tier_generations {}", dynamic_max_rewrite_generation, hot_tier_generations, cold_tier_generations); @@ -637,12 +637,12 @@ ExtentPlacementManager::close() void ExtentPlacementManager::BackgroundProcess::log_state(const char *caller) const { LOG_PREFIX(BackgroundProcess::log_state); - DEBUG("caller {}, {}, {}", + INFO("caller {}, {}, {}", caller, JournalTrimmerImpl::stat_printer_t{*trimmer, true}, AsyncCleaner::stat_printer_t{*main_cleaner, true}); if (has_cold_tier()) { - DEBUG("caller {}, cold_cleaner: {}", + INFO("caller {}, cold_cleaner: {}", caller, AsyncCleaner::stat_printer_t{*cold_cleaner, true}); } @@ -1020,6 +1020,7 @@ seastar::future<> ExtentPlacementManager::BackgroundProcess::do_background_cycle() { LOG_PREFIX(BackgroundProcess::do_background_cycle); + INFO(""); assert(is_ready()); bool should_trim = trimmer->should_trim(); bool proceed_trim = false; @@ -1057,10 +1058,10 @@ ExtentPlacementManager::BackgroundProcess::do_background_cycle() } if (proceed_trim) { - DEBUG("started trimming..."); + INFO("started trimming..."); return trimmer->trim(force_trim ).finally([this, trim_usage, should_abort_cleaner_usage, FNAME] { - DEBUG("finished trimming"); + INFO("finished trimming"); if (should_abort_cleaner_usage) { abort_cleaner_usage(trim_usage, {true, true}); } @@ -1100,6 +1101,9 @@ ExtentPlacementManager::BackgroundProcess::do_background_cycle() logical_bucket->should_demote())) { proceed_demote = true; } + INFO("proceed_demote: {}, could_demote: {}, fast_mode: {}, should_demote {}", + proceed_demote, logical_bucket->could_demote(), + eviction_state.is_fast_mode(), logical_bucket->should_demote()); bool abort_cold_cleaner_usage = true; if (unlikely(test_workload && force_process_state == ForceProcessState::CLEAN)) { diff --git a/src/crimson/os/seastore/extent_placement_manager.h b/src/crimson/os/seastore/extent_placement_manager.h index a533fbbd0d3..01142294ffb 100644 --- a/src/crimson/os/seastore/extent_placement_manager.h +++ b/src/crimson/os/seastore/extent_placement_manager.h @@ -745,6 +745,7 @@ private: rewrite_gen_t gen, write_policy_t policy, bool is_tracked) { + LOG_PREFIX(ExtentPlacementManager::adjust_generation); assert(is_real_type(type)); if (is_root_type(type)) { gen = INLINE_GENERATION; @@ -792,6 +793,7 @@ private: hint != placement_hint_t::REWRITE && hint != placement_hint_t::COLD) { gen = hot_tier_generations - 1; + SUBINFO(seastore_epm, "setting gen to {}", gen); } if (gen > dynamic_max_rewrite_generation) { @@ -1098,6 +1100,8 @@ private: } seastar::future<> wait_background() { + LOG_PREFIX(BackgroundProcess::wait_background); + SUBINFO(seastore_epm, ""); if (!blocking_io) { blocking_io = seastar::promise<>(); } @@ -1206,7 +1210,7 @@ private: } struct eviction_state_t { - enum class eviction_mode_t { + enum class eviction_mode_t : uint8_t { STOP, // generation greater than or equal to MIN_COLD_GENERATION // will be set to MIN_COLD_GENERATION - 1, which means // no extents will be evicted. @@ -1252,6 +1256,8 @@ private: rewrite_gen_t adjust_generation_with_eviction(rewrite_gen_t gen) { rewrite_gen_t ret = gen; + LOG_PREFIX(eviction_state_t::adjust_generation_with_eviction); + SUBINFO(seastore_epm, "gen={} mode={}", gen, (uint8_t)eviction_mode); switch(eviction_mode) { case eviction_mode_t::STOP: if (gen == hot_tier_generations) { diff --git a/src/crimson/os/seastore/logical_bucket.cc b/src/crimson/os/seastore/logical_bucket.cc index f234274bdcd..47989356c55 100644 --- a/src/crimson/os/seastore/logical_bucket.cc +++ b/src/crimson/os/seastore/logical_bucket.cc @@ -41,11 +41,11 @@ public: assert(laddr == laddr.get_object_prefix()); auto iter = index.find(laddr); if (iter != index.end()) { - TRACE("find bucket: {}", iter->first); + INFO("find bucket: {}", iter->first); iter->second->demoting = false; lru.splice(lru.end(), lru, iter->second); } else { - TRACE("create bucket: {}", laddr); + INFO("create bucket: {}", laddr); index[laddr] = lru.emplace(lru.end(), laddr); if (should_demote()) { assert(listener); @@ -124,7 +124,7 @@ public: co_await ecb->submit_transaction_direct(t); - DEBUGT("finish demoting {} buckets with {} bytes evicted and {} bytes demoted", + INFOT("finish demoting {} buckets with {} bytes evicted and {} bytes demoted", t, completed_buckets.size(), evicted_size, demoted_size); stat.demoted_bucket_count += completed_buckets.size(); stat.demoted_size += demoted_size; @@ -169,7 +169,7 @@ private: auto iter = index.find(laddr); if (iter != index.end()) { if (iter->second->demoting) { - DEBUG("remove bucket: {}", laddr); + INFO("remove bucket: {}", laddr); lru.erase(iter->second); index.erase(iter); } else { diff --git a/src/crimson/os/seastore/transaction_manager.cc b/src/crimson/os/seastore/transaction_manager.cc index 449502945c2..245a2e7d649 100644 --- a/src/crimson/os/seastore/transaction_manager.cc +++ b/src/crimson/os/seastore/transaction_manager.cc @@ -923,7 +923,7 @@ TransactionManager::rewrite_logical_extent( } nextent->rewrite(t, *extent, 0); - DEBUGT("rewriting meta -- {} to {}", t, *extent, *nextent); + INFOT("rewriting meta -- {} to {}", t, *extent, *nextent); #ifndef NDEBUG if (get_checksum_needed(extent->get_paddr())) { @@ -991,7 +991,7 @@ TransactionManager::rewrite_logical_extent( bool first_extent = (off == 0); ceph_assert(left >= nextent->get_length()); nextent->rewrite(t, *extent, off); - DEBUGT("rewriting data -- {} to {}", t, *extent, *nextent); + INFOT("rewriting data -- {} to {}", t, *extent, *nextent); /* This update_mapping is, strictly speaking, unnecessary for delayed_alloc * extents since we're going to do it again once we either do the ool write @@ -1250,7 +1250,7 @@ TransactionManager::promote_extent( { LOG_PREFIX(TransactionManager::promote_extent); assert(epm->is_cold_device(extent->get_paddr().get_device_id())); - DEBUGT("promote extent: {}", t, *extent); + INFOT("promote extent: {}", t, *extent); ceph_assert(extent->is_logical()); std::vector promoted_extents; @@ -1512,7 +1512,7 @@ TransactionManager::demote_region( { LOG_PREFIX(TransactionManager::demote_region); auto prefix = start.get_object_prefix(); - DEBUGT("start demote {}", t, prefix); + INFOT("start demote {}", t, prefix); auto cursor = co_await lba_manager->upper_bound_right( t, start ).handle_error_interruptible( @@ -1531,7 +1531,7 @@ TransactionManager::demote_region( continue; } if (it.has_shadow_val()) { - DEBUGT("demote shadow {}", t, it); + INFOT("demote shadow {}", t, it); auto extent = co_await relocate_shadow_extent(t, it); ret.demoted_size += extent->get_length(); auto cursor = co_await lba_manager->demote_extent( @@ -1540,14 +1540,14 @@ TransactionManager::demote_region( it = co_await nit.next(); } else if (!it.is_indirect() && !it.is_zero_reserved() && !epm->is_cold_device(it.get_val().get_device_id())) { - DEBUGT("demote hot {}", t, it); + INFOT("demote hot {}", t, it); auto extent = co_await read_cursor_by_type( t, it.direct_cursor, it.get_extent_type()); ret.evicted_size += extent->get_length(); extents.push_back(extent); it = co_await it.next(); } else { - DEBUGT("skip {}", t, it); + INFOT("skip {}", t, it); it = co_await it.next(); } }