Merge pull request ceph#60904 from cyx1231st/wip-seastore-hex-log

crimson/os/seastore: convert offset/length in logs to hex format

Reviewed-by: Xuehan Xu <xuxuehan@qianxin.com>

Author: cyx1231st

src/crimson/os/seastore/async_cleaner.cc

@@ -131,7 +131,7 @@ void segments_info_t::add_segment_manager(
   auto ssize = segment_manager.get_segment_size();
   auto nsegments = segment_manager.get_num_segments();
   auto sm_size = segment_manager.get_available_size();
-  INFO("adding segment manager {}, size={}, ssize={}, segments={}",
+  INFO("adding segment manager {}, size=0x{:x}, segment size=0x{:x}, segments={}",
        device_id_printer_t{d_id}, sm_size, ssize, nsegments);
   ceph_assert(ssize > 0);
   ceph_assert(nsegments > 0);
@@ -329,9 +329,9 @@ std::ostream &operator<<(std::ostream &os, const segments_info_t &infos)
             << ", closed=" << infos.get_num_closed()
             << ", type_journal=" << infos.get_num_type_journal()
             << ", type_ool=" << infos.get_num_type_ool()
-            << ", total=" << infos.get_total_bytes() << "B"
-            << ", available=" << infos.get_available_bytes() << "B"
-            << ", unavailable=" << infos.get_unavailable_bytes() << "B"
+            << ", total=0x" << std::hex << infos.get_total_bytes() << "B"
+            << ", available=0x" << infos.get_available_bytes() << "B"
+            << ", unavailable=0x" << infos.get_unavailable_bytes() << "B" << std::dec
             << ", available_ratio=" << infos.get_available_ratio()
             << ", submitted_head=" << infos.get_submitted_journal_head()
             << ", time_bound=" << sea_time_point_printer_t{infos.get_time_bound()}
@@ -765,10 +765,10 @@ int64_t SpaceTrackerDetailed::SegmentMap::allocate(
   for (auto i = b; i < e; ++i) {
     if (bitmap[i]) {
       if (!error) {
-        ERROR("found allocated in {}, {} ~ {}", segment, offset, len);
+        ERROR("found allocated in {}, 0x{:x}~0x{:x}", segment, offset, len);
 	error = true;
       }
-      DEBUG("block {} allocated", i * block_size);
+      DEBUG("block 0x{:x}B allocated", i * block_size);
     }
     bitmap[i] = true;
   }
@@ -792,10 +792,10 @@ int64_t SpaceTrackerDetailed::SegmentMap::release(
   for (auto i = b; i < e; ++i) {
     if (!bitmap[i]) {
       if (!error) {
-	ERROR("found unallocated in {}, {} ~ {}", segment, offset, len);
+	ERROR("found unallocated in {}, 0x{:x}~0x{:x}", segment, offset, len);
 	error = true;
       }
-      DEBUG("block {} unallocated", i * block_size);
+      DEBUG("block 0x{:x}B unallocated", i * block_size);
     }
     bitmap[i] = false;
   }
@@ -831,7 +831,7 @@ void SpaceTrackerDetailed::SegmentMap::dump_usage(extent_len_t block_size) const
   INFO("dump start");
   for (unsigned i = 0; i < bitmap.size(); ++i) {
     if (bitmap[i]) {
-      LOCAL_LOGGER.info("    {} still live", i * block_size);
+      LOCAL_LOGGER.info("    0x{:x}B still live", i * block_size);
     }
   }
 }
@@ -847,7 +847,7 @@ void SpaceTrackerDetailed::dump_usage(segment_id_t id) const
 void SpaceTrackerSimple::dump_usage(segment_id_t id) const
 {
   LOG_PREFIX(SpaceTrackerSimple::dump_usage);
-  INFO("id: {}, live_bytes: {}",
+  INFO("id: {}, live_bytes: 0x{:x}",
        id, live_bytes_by_segment[id].live_bytes);
 }
 
@@ -1165,7 +1165,7 @@ SegmentCleaner::do_reclaim_space(
 	    [this, &extents, &t](auto &ent)
 	  {
 	    LOG_PREFIX(SegmentCleaner::do_reclaim_space);
-	    TRACET("getting extent of type {} at {}~{}",
+	    TRACET("getting extent of type {} at {}~0x{:x}",
 	      t,
 	      ent.type,
 	      ent.paddr,
@@ -1568,7 +1568,7 @@ void SegmentCleaner::mark_space_used(
 
   background_callback->maybe_wake_background();
   assert(ret > 0);
-  DEBUG("segment {} new len: {}~{}, live_bytes: {}",
+  DEBUG("segment {} new len: {}~0x{:x}, live_bytes: 0x{:x}",
         seg_addr.get_segment_id(),
         addr,
         len,
@@ -1591,7 +1591,7 @@ void SegmentCleaner::mark_space_free(
   stats.used_bytes -= len;
   auto& seg_addr = addr.as_seg_paddr();
 
-  DEBUG("segment {} free len: {}~{}",
+  DEBUG("segment {} free len: {}~0x{:x}",
         seg_addr.get_segment_id(), addr, len);
   auto old_usage = calc_utilization(seg_addr.get_segment_id());
   [[maybe_unused]] auto ret = space_tracker->release(
@@ -1602,7 +1602,7 @@ void SegmentCleaner::mark_space_free(
   adjust_segment_util(old_usage, new_usage);
   background_callback->maybe_wake_blocked_io();
   assert(ret >= 0);
-  DEBUG("segment {} free len: {}~{}, live_bytes: {}",
+  DEBUG("segment {} free len: {}~0x{:x}, live_bytes: 0x{:x}",
         seg_addr.get_segment_id(),
         addr,
         len,
@@ -1687,11 +1687,11 @@ void SegmentCleaner::print(std::ostream &os, bool is_detailed) const
      << ", reclaim_ratio=" << get_reclaim_ratio()
      << ", alive_ratio=" << get_alive_ratio();
   if (is_detailed) {
-    os << ", unavailable_unreclaimable="
+    os << ", unavailable_unreclaimable=0x" << std::hex
        << get_unavailable_unreclaimable_bytes() << "B"
-       << ", unavailable_reclaimble="
+       << ", unavailable_reclaimble=0x"
        << get_unavailable_reclaimable_bytes() << "B"
-       << ", alive=" << stats.used_bytes << "B"
+       << ", alive=0x" << stats.used_bytes << "B" << std::dec
        << ", " << segments;
   }
   os << ")";
@@ -1722,7 +1722,7 @@ void RBMCleaner::mark_space_used(
   for (auto rbm : rbms) {
     if (addr.get_device_id() == rbm->get_device_id()) {
       if (rbm->get_start() <= addr) {
-	DEBUG("allocate addr: {} len: {}", addr, len);
+	DEBUG("allocate addr: {} len: 0x{:x}", addr, len);
 	stats.used_bytes += len;
 	rbm->mark_space_used(addr, len);
       }
@@ -1741,7 +1741,7 @@ void RBMCleaner::mark_space_free(
   for (auto rbm : rbms) {
     if (addr.get_device_id() == rbm->get_device_id()) {
       if (rbm->get_start() <= addr) {
-	DEBUG("free addr: {} len: {}", addr, len);
+	DEBUG("free addr: {} len: 0x{:x}", addr, len);
 	ceph_assert(stats.used_bytes >= len);
 	stats.used_bytes -= len;
 	rbm->mark_space_free(addr, len);

src/crimson/os/seastore/cache.cc

@@ -30,7 +30,7 @@ namespace crimson::os::seastore {
 
 std::ostream &operator<<(std::ostream &out, const backref_entry_t &ent) {
   return out << "backref_entry_t{"
-	     << ent.paddr << "~" << ent.len << ", "
+	     << ent.paddr << "~0x" << std::hex << ent.len << std::dec << ", "
 	     << "laddr: " << ent.laddr << ", "
 	     << "type: " << ent.type << ", "
 	     << "seq: " << ent.seq << ", "
@@ -44,7 +44,7 @@ Cache::Cache(
 	  "seastore_cache_lru_size"))
 {
   LOG_PREFIX(Cache::Cache);
-  INFO("created, lru_capacity={}B", lru.get_capacity_bytes());
+  INFO("created, lru_capacity=0x{:x}B", lru.get_capacity_bytes());
   register_metrics();
   segment_providers_by_device_id.resize(DEVICE_ID_MAX, nullptr);
 }

src/crimson/os/seastore/cache.h

@@ -1336,7 +1336,7 @@ class Cache {
   {
     LOG_PREFIX(Cache::init_cached_extents);
     SUBINFOT(seastore_cache,
-        "start with {}({}B) extents, {} dirty, dirty_from={}, alloc_from={}",
+        "start with {}(0x{:x}B) extents, {} dirty, dirty_from={}, alloc_from={}",
         t,
         extents_index.size(),
         extents_index.get_bytes(),
@@ -1379,7 +1379,7 @@ class Cache {
       }
     ).si_then([this, FNAME, &t] {
       SUBINFOT(seastore_cache,
-          "finish with {}({}B) extents, {} dirty, dirty_from={}, alloc_from={}",
+          "finish with {}(0x{:x}B) extents, {} dirty, dirty_from={}, alloc_from={}",
           t,
           extents_index.size(),
           extents_index.get_bytes(),

src/crimson/os/seastore/device.cc

@@ -12,7 +12,7 @@ namespace crimson::os::seastore {
 std::ostream& operator<<(std::ostream& out, const device_spec_t& ds)
 {
   return out << "device_spec("
-             << "magic=" << ds.magic
+             << "magic=0x" << std::hex << ds.magic << std::dec
              << ", dtype=" << ds.dtype
              << ", " << device_id_printer_t{ds.id}
              << ")";

src/crimson/os/seastore/extent_placement_manager.cc

@@ -1069,8 +1069,8 @@ RandomBlockOolWriter::do_write(
       w_info.bp = bp;
       writes.push_back(w_info);
     }
-    TRACE("current extent: base off {} len {},\
-      maybe-merged current extent: base off {} len {}",
+    TRACE("current extent: {}~0x{:x},\
+      maybe-merged current extent: {}~0x{:x}",
       paddr, ex->get_length(), writes.back().offset, writes.back().bp.length());
   }
 

src/crimson/os/seastore/extent_placement_manager.h

@@ -236,9 +236,9 @@ struct io_usage_t {
   cleaner_usage_t cleaner_usage;
   friend std::ostream &operator<<(std::ostream &out, const io_usage_t &usage) {
     return out << "io_usage_t("
-               << "inline_usage=" << usage.inline_usage
-               << ", main_cleaner_usage=" << usage.cleaner_usage.main_usage
-               << ", cold_cleaner_usage=" << usage.cleaner_usage.cold_ool_usage
+               << "inline_usage=0x" << std::hex << usage.inline_usage
+               << ", main_cleaner_usage=0x" << usage.cleaner_usage.main_usage
+               << ", cold_cleaner_usage=0x" << usage.cleaner_usage.cold_ool_usage << std::dec
                << ")";
   }
 };
@@ -424,7 +424,7 @@ class ExtentPlacementManager {
                         : ext.start + (ext.len - left);
           allocs.emplace_back(alloc_result_t{start, std::move(bp), gen});
           SUBDEBUGT(seastore_epm,
-                    "allocated {} {}B extent at {}, hint={}, gen={}",
+                    "allocated {} 0x{:x}B extent at {}, hint={}, gen={}",
                     t, type, len, start, hint, gen);
           left -= len;
         }

src/crimson/os/seastore/extentmap_manager.cc

@@ -24,7 +24,7 @@ RecordBatch::add_pending(
   LOG_PREFIX(RecordBatch::add_pending);
   auto new_size = get_encoded_length_after(record, block_size);
   auto dlength_offset = pending.size.dlength;
-  TRACE("{} batches={}, write_size={}, dlength_offset={} ...",
+  TRACE("{} batches={}, write_size=0x{:x}, dlength_offset=0x{:x} ...",
         name,
         pending.get_size() + 1,
         new_size.get_encoded_length(),
@@ -144,7 +144,7 @@ RecordSubmitter::RecordSubmitter(
     batches(new RecordBatch[io_depth + 1])
 {
   LOG_PREFIX(RecordSubmitter);
-  INFO("{} io_depth_limit={}, batch_capacity={}, batch_flush_size={}, "
+  INFO("{} io_depth_limit={}, batch_capacity={}, batch_flush_size=0x{:x}, "
        "preferred_fullness={}",
        get_name(), io_depth, batch_capacity,
        batch_flush_size, preferred_fullness);

src/crimson/os/seastore/journal/record_submitter.cc

@@ -189,7 +189,7 @@ SegmentAllocator::write(ceph::bufferlist&& to_write)
   auto write_length = to_write.length();
   auto write_start_offset = written_to;
   if (unlikely(LOCAL_LOGGER.is_enabled(seastar::log_level::trace))) {
-    TRACE("{} {}~{}", print_name, get_written_to(), write_length);
+    TRACE("{} {}~0x{:x}", print_name, get_written_to(), write_length);
   }
   assert(write_length > 0);
   assert((write_length % get_block_size()) == 0);
@@ -250,7 +250,7 @@ SegmentAllocator::close_segment()
     close_seg_info.num_extents};
   ceph::bufferlist bl;
   encode(tail, bl);
-  INFO("{} close segment {}, written_to={}",
+  INFO("{} close segment {}, written_to=0x{:x}",
        print_name,
        tail,
        written_to);

src/crimson/os/seastore/journal/segment_allocator.cc

@@ -424,7 +424,7 @@ SegmentedJournal::submit_record(
   ).get_encoded_length();
   auto max_record_length = journal_segment_allocator.get_max_write_length();
   if (expected_size > max_record_length) {
-    ERROR("H{} {} exceeds max record size {}",
+    ERROR("H{} {} exceeds max record size 0x{:x}",
           (void*)&handle, record, max_record_length);
     return crimson::ct_error::erange::make();
   }