From b9f8a49eb6be7873b827f93a428630341c66f633 Mon Sep 17 00:00:00 2001 From: Yingxin Cheng Date: Mon, 4 Jul 2022 11:46:44 +0800 Subject: [PATCH] crimson/os/seastore: cleanup printing device-id Signed-off-by: Yingxin Cheng --- src/crimson/os/seastore/device.cc | 2 +- .../journal/circular_bounded_journal.cc | 1 + .../os/seastore/journal/segment_allocator.cc | 6 +- .../random_block_manager/nvmedevice.cc | 8 +- src/crimson/os/seastore/seastore_types.cc | 14 +- .../os/seastore/segment_manager/block.cc | 141 ++++++++---------- 6 files changed, 77 insertions(+), 95 deletions(-) diff --git a/src/crimson/os/seastore/device.cc b/src/crimson/os/seastore/device.cc index 0b21cac8ef2..6eab7a27e2e 100644 --- a/src/crimson/os/seastore/device.cc +++ b/src/crimson/os/seastore/device.cc @@ -12,7 +12,7 @@ std::ostream& operator<<(std::ostream& out, const device_spec_t& ds) return out << "device_spec(" << "magic=" << ds.magic << ", dtype=" << ds.dtype - << ", id=" << device_id_printer_t{ds.id} + << ", " << device_id_printer_t{ds.id} << ")"; } diff --git a/src/crimson/os/seastore/journal/circular_bounded_journal.cc b/src/crimson/os/seastore/journal/circular_bounded_journal.cc index f82ba9c7023..8f0b047f86b 100644 --- a/src/crimson/os/seastore/journal/circular_bounded_journal.cc +++ b/src/crimson/os/seastore/journal/circular_bounded_journal.cc @@ -21,6 +21,7 @@ std::ostream &operator<<(std::ostream &out, << ", size=" << header.size << ", journal_tail=" << header.journal_tail << ", applied_to="<< header.applied_to + << ", "<< device_id_printer_t{header.device_id} << ")"; } diff --git a/src/crimson/os/seastore/journal/segment_allocator.cc b/src/crimson/os/seastore/journal/segment_allocator.cc index 5f0106c8410..47911c6425e 100644 --- a/src/crimson/os/seastore/journal/segment_allocator.cc +++ b/src/crimson/os/seastore/journal/segment_allocator.cc @@ -125,12 +125,10 @@ SegmentAllocator::open() auto& device_ids = sm_group.get_device_ids(); ceph_assert(device_ids.size()); std::ostringstream oss; - oss << "D"; for (auto& device_id : device_ids) { - oss << "_" << device_id_printer_t{device_id}; + oss << device_id_printer_t{device_id} << "_"; } - oss << "_" - << fmt::format("{}_G{}", category, gen); + oss << fmt::format("{}_G{}", category, gen); print_name = oss.str(); INFO("{}", print_name); diff --git a/src/crimson/os/seastore/random_block_manager/nvmedevice.cc b/src/crimson/os/seastore/random_block_manager/nvmedevice.cc index a0ebd4a2b5a..365a371000a 100644 --- a/src/crimson/os/seastore/random_block_manager/nvmedevice.cc +++ b/src/crimson/os/seastore/random_block_manager/nvmedevice.cc @@ -164,13 +164,13 @@ write_ertr::future<> PosixNVMeDevice::writev( ).handle_exception( [this, off, len](auto e) -> write_ertr::future { - logger().error("D{} poffset={}~{} dma_write got error -- {}", - get_device_id(), off, len, e); + logger().error("{} poffset={}~{} dma_write got error -- {}", + device_id_printer_t{get_device_id()}, off, len, e); return crimson::ct_error::input_output_error::make(); }).then([this, off, len](size_t written) -> write_ertr::future<> { if (written != len) { - logger().error("D{} poffset={}~{} dma_write len={} inconsistent", - get_device_id(), off, len, written); + logger().error("{} poffset={}~{} dma_write len={} inconsistent", + device_id_printer_t{get_device_id()}, off, len, written); return crimson::ct_error::input_output_error::make(); } return write_ertr::now(); diff --git a/src/crimson/os/seastore/seastore_types.cc b/src/crimson/os/seastore/seastore_types.cc index db77a2f13e0..7ad95e11516 100644 --- a/src/crimson/os/seastore/seastore_types.cc +++ b/src/crimson/os/seastore/seastore_types.cc @@ -37,19 +37,19 @@ std::ostream &operator<<(std::ostream &out, const device_id_printer_t &id) { auto _id = id.id; if (_id == DEVICE_ID_NULL) { - return out << "DEVICE_ID_NULL"; + return out << "Dev(NULL)"; } else if (_id == DEVICE_ID_RECORD_RELATIVE) { - return out << "DEVICE_ID_RR"; + return out << "Dev(RR)"; } else if (_id == DEVICE_ID_BLOCK_RELATIVE) { - return out << "DEVICE_ID_BR"; + return out << "Dev(BR)"; } else if (_id == DEVICE_ID_DELAYED) { - return out << "DEVICE_ID_DELAYED"; + return out << "Dev(DELAYED)"; } else if (_id == DEVICE_ID_FAKE) { - return out << "DEVICE_ID_FAKE"; + return out << "Dev(FAKE)"; } else if (_id == DEVICE_ID_ZERO) { - return out << "DEVICE_ID_ZERO"; + return out << "Dev(ZERO)"; } else { - return out << (unsigned)_id; + return out << "Dev(" << (unsigned)_id << ")"; } } diff --git a/src/crimson/os/seastore/segment_manager/block.cc b/src/crimson/os/seastore/segment_manager/block.cc index 124be2cbdcc..4435c45151a 100644 --- a/src/crimson/os/seastore/segment_manager/block.cc +++ b/src/crimson/os/seastore/segment_manager/block.cc @@ -60,23 +60,24 @@ static write_ertr::future<> do_write( { LOG_PREFIX(block_do_write); auto len = bptr.length(); - TRACE("D{} poffset={}~{} ...", device_id, offset, len); + TRACE("{} poffset={}~{} ...", + device_id_printer_t{device_id}, offset, len); return device.dma_write( offset, bptr.c_str(), len ).handle_exception( [FNAME, device_id, offset, len](auto e) -> write_ertr::future { - ERROR("D{} poffset={}~{} got error -- {}", - device_id, offset, len, e); + ERROR("{} poffset={}~{} got error -- {}", + device_id_printer_t{device_id}, offset, len, e); return crimson::ct_error::input_output_error::make(); }).then([FNAME, device_id, offset, len](auto result) -> write_ertr::future<> { if (result != len) { - ERROR("D{} poffset={}~{} write len={} inconsistent", - device_id, offset, len, result); + ERROR("{} poffset={}~{} write len={} inconsistent", + device_id_printer_t{device_id}, offset, len, result); return crimson::ct_error::input_output_error::make(); } - TRACE("D{} poffset={}~{} done", device_id, offset, len); + TRACE("{} poffset={}~{} done", device_id_printer_t{device_id}, offset, len); return write_ertr::now(); }); } @@ -89,8 +90,8 @@ static write_ertr::future<> do_writev( size_t block_size) { LOG_PREFIX(block_do_writev); - TRACE("D{} poffset={}~{}, {} buffers", - device_id, offset, bl.length(), bl.get_num_buffers()); + TRACE("{} poffset={}~{}, {} buffers", + device_id_printer_t{device_id}, offset, bl.length(), bl.get_num_buffers()); // writev requires each buffer to be aligned to the disks' block // size, we need to rebuild here @@ -108,23 +109,23 @@ static write_ertr::future<> do_writev( auto off = offset + p.offset; auto len = p.length; auto& iov = p.iov; - TRACE("D{} poffset={}~{} dma_write ...", - device_id, off, len); + TRACE("{} poffset={}~{} dma_write ...", + device_id_printer_t{device_id}, off, len); return device.dma_write(off, std::move(iov) ).handle_exception( [FNAME, device_id, off, len](auto e) -> write_ertr::future { - ERROR("D{} poffset={}~{} dma_write got error -- {}", - device_id, off, len, e); + ERROR("{} poffset={}~{} dma_write got error -- {}", + device_id_printer_t{device_id}, off, len, e); return crimson::ct_error::input_output_error::make(); }).then([FNAME, device_id, off, len](size_t written) -> write_ertr::future<> { if (written != len) { - ERROR("D{} poffset={}~{} dma_write len={} inconsistent", - device_id, off, len, written); + ERROR("{} poffset={}~{} dma_write len={} inconsistent", + device_id_printer_t{device_id}, off, len, written); return crimson::ct_error::input_output_error::make(); } - TRACE("D{} poffset={}~{} dma_write done", - device_id, off, len); + TRACE("{} poffset={}~{} dma_write done", + device_id_printer_t{device_id}, off, len); return write_ertr::now(); }); }); @@ -139,7 +140,7 @@ static read_ertr::future<> do_read( bufferptr &bptr) { LOG_PREFIX(block_do_read); - TRACE("D{} poffset={}~{} ...", device_id, offset, len); + TRACE("{} poffset={}~{} ...", device_id_printer_t{device_id}, offset, len); assert(len <= bptr.length()); return device.dma_read( offset, @@ -152,16 +153,16 @@ static read_ertr::future<> do_read( // once seastar::future::handle_exception() returns seastar::futurize_t [FNAME, device_id, offset, len](auto e) -> read_ertr::future { - ERROR("D{} poffset={}~{} got error -- {}", - device_id, offset, len, e); + ERROR("{} poffset={}~{} got error -- {}", + device_id_printer_t{device_id}, offset, len, e); return crimson::ct_error::input_output_error::make(); }).then([FNAME, device_id, offset, len](auto result) -> read_ertr::future<> { if (result != len) { - ERROR("D{} poffset={}~{} read len={} inconsistent", - device_id, offset, len, result); + ERROR("{} poffset={}~{} read len={} inconsistent", + device_id_printer_t{device_id}, offset, len, result); return crimson::ct_error::input_output_error::make(); } - TRACE("D{} poffset={}~{} done", device_id, offset, len); + TRACE("{} poffset={}~{} done", device_id_printer_t{device_id}, offset, len); return read_ertr::now(); }); } @@ -173,7 +174,8 @@ SegmentStateTracker::write_out( uint64_t offset) { LOG_PREFIX(SegmentStateTracker::write_out); - DEBUG("D{} poffset={}~{}", device_id, offset, bptr.length()); + DEBUG("{} poffset={}~{}", + device_id_printer_t{device_id}, offset, bptr.length()); return do_write(device_id, device, offset, bptr); } @@ -184,7 +186,8 @@ SegmentStateTracker::read_in( uint64_t offset) { LOG_PREFIX(SegmentStateTracker::read_in); - DEBUG("D{} poffset={}~{}", device_id, offset, bptr.length()); + DEBUG("{} poffset={}~{}", + device_id_printer_t{device_id}, offset, bptr.length()); return do_read( device_id, device, @@ -217,9 +220,9 @@ block_sm_superblock_t make_superblock( size_t first_seg_off = tracker_size + tracker_off; size_t segments = (size - first_seg_off) / config_segment_size; - INFO("D{} disk_size={}, segment_size={}, segments={}, block_size={}, " + INFO("{} disk_size={}, segment_size={}, segments={}, block_size={}, " "tracker_off={}, first_seg_off={}", - device_id, + device_id_printer_t{device_id}, size, config_segment_size, segments, @@ -324,7 +327,7 @@ write_superblock( block_sm_superblock_t sb) { LOG_PREFIX(block_write_superblock); - DEBUG("D{} write {}", device_id, sb); + DEBUG("{} write {}", device_id_printer_t{device_id}, sb); sb.validate(); assert(ceph::encoded_sizeof(sb) < sb.block_size); @@ -396,32 +399,20 @@ Segment::write_ertr::future<> BlockSegment::write( { LOG_PREFIX(BlockSegment::write); auto paddr = paddr_t::make_seg_paddr(id, offset); - DEBUG("D{} S{} offset={}~{} poffset={} ...", - id.device_id(), - id.device_segment_id(), - offset, - bl.length(), - manager.get_offset(paddr)); + DEBUG("{} offset={}~{} poffset={} ...", + id, offset, bl.length(), manager.get_offset(paddr)); if (offset < write_pointer || offset % manager.superblock.block_size != 0 || bl.length() % manager.superblock.block_size != 0) { - ERROR("D{} S{} offset={}~{} poffset={} invalid write", - id.device_id(), - id.device_segment_id(), - offset, - bl.length(), - manager.get_offset(paddr)); + ERROR("{} offset={}~{} poffset={} invalid write", + id, offset, bl.length(), manager.get_offset(paddr)); return crimson::ct_error::invarg::make(); } if (offset + bl.length() > manager.superblock.segment_size) { - ERROR("D{} S{} offset={}~{} poffset={} write out of the range {}", - id.device_id(), - id.device_segment_id(), - offset, - bl.length(), - manager.get_offset(paddr), + ERROR("{} offset={}~{} poffset={} write out of the range {}", + id, offset, bl.length(), manager.get_offset(paddr), manager.superblock.segment_size); return crimson::ct_error::enospc::make(); } @@ -436,8 +427,7 @@ Segment::close_ertr::future<> BlockSegmentManager::segment_close( LOG_PREFIX(BlockSegmentManager::segment_close); auto s_id = id.device_segment_id(); int unused_bytes = get_segment_size() - write_pointer; - INFO("D{} S{} unused_bytes={} ...", - get_device_id(), s_id, unused_bytes); + INFO("{} unused_bytes={} ...", id, unused_bytes); assert(unused_bytes >= 0); assert(id.device_id() == get_device_id()); @@ -482,7 +472,7 @@ BlockSegmentManager::mount_ret BlockSegmentManager::mount() return read_superblock(device, sd); }).safe_then([=](auto sb) { set_device_id(sb.config.spec.id); - INFO("D{} read {}", get_device_id(), sb); + INFO("{} read {}", device_id_printer_t{get_device_id()}, sb); sb.validate(); superblock = sb; stats.data_read.increment( @@ -506,7 +496,7 @@ BlockSegmentManager::mount_ret BlockSegmentManager::mount() get_device_id(), device, superblock.tracker_offset); }); }).safe_then([this, FNAME] { - INFO("D{} complete", get_device_id()); + INFO("{} complete", device_id_printer_t{get_device_id()}); register_metrics(); }); } @@ -516,7 +506,8 @@ BlockSegmentManager::mkfs_ret BlockSegmentManager::mkfs( { LOG_PREFIX(BlockSegmentManager::mkfs); set_device_id(sm_config.spec.id); - INFO("D{} path={}, {}", get_device_id(), device_path, sm_config); + INFO("{} path={}, {}", + device_id_printer_t{get_device_id()}, device_path, sm_config); return seastar::do_with( seastar::file{}, seastar::stat_data{}, @@ -541,7 +532,7 @@ BlockSegmentManager::mkfs_ret BlockSegmentManager::mkfs( ceph::encoded_sizeof(sb)); return write_superblock(get_device_id(), device, sb); }).safe_then([&, FNAME, this] { - DEBUG("D{} superblock written", get_device_id()); + DEBUG("{} superblock written", device_id_printer_t{get_device_id()}); tracker.reset(new SegmentStateTracker(sb.segments, sb.block_size)); stats.metadata_write.increment(tracker->get_size()); return tracker->write_out( @@ -549,7 +540,7 @@ BlockSegmentManager::mkfs_ret BlockSegmentManager::mkfs( }).finally([&] { return device.close(); }).safe_then([FNAME, this] { - INFO("D{} complete", get_device_id()); + INFO("{} complete", device_id_printer_t{get_device_id()}); return mkfs_ertr::now(); }); }); @@ -558,7 +549,7 @@ BlockSegmentManager::mkfs_ret BlockSegmentManager::mkfs( BlockSegmentManager::close_ertr::future<> BlockSegmentManager::close() { LOG_PREFIX(BlockSegmentManager::close); - INFO("D{}", get_device_id()); + INFO("{}", device_id_printer_t{get_device_id()}); metrics.clear(); return device.close(); } @@ -568,19 +559,17 @@ SegmentManager::open_ertr::future BlockSegmentManager::open( { LOG_PREFIX(BlockSegmentManager::open); auto s_id = id.device_segment_id(); - INFO("D{} S{} ...", get_device_id(), s_id); + INFO("{} ...", id); assert(id.device_id() == get_device_id()); if (s_id >= get_num_segments()) { - ERROR("D{} S{} segment-id out of range {}", - get_device_id(), s_id, get_num_segments()); + ERROR("{} segment-id out of range {}", id, get_num_segments()); return crimson::ct_error::invarg::make(); } if (tracker->get(s_id) != segment_state_t::EMPTY) { - ERROR("D{} S{} invalid state {} != EMPTY", - get_device_id(), s_id, tracker->get(s_id)); + ERROR("{} invalid state {} != EMPTY", id, tracker->get(s_id)); return crimson::ct_error::invarg::make(); } @@ -590,7 +579,7 @@ SegmentManager::open_ertr::future BlockSegmentManager::open( get_device_id(), device, superblock.tracker_offset ).safe_then([this, id, FNAME] { ++stats.opened_segments; - DEBUG("D{} S{} done", get_device_id(), id.device_segment_id()); + DEBUG("{} done", id); return open_ertr::future( open_ertr::ready_future_marker{}, SegmentRef(new BlockSegment(*this, id))); @@ -602,19 +591,17 @@ SegmentManager::release_ertr::future<> BlockSegmentManager::release( { LOG_PREFIX(BlockSegmentManager::release); auto s_id = id.device_segment_id(); - INFO("D{} S{} ...", get_device_id(), s_id); + INFO("{} ...", id); assert(id.device_id() == get_device_id()); if (s_id >= get_num_segments()) { - ERROR("D{} S{} segment-id out of range {}", - get_device_id(), s_id, get_num_segments()); + ERROR("{} segment-id out of range {}", id, get_num_segments()); return crimson::ct_error::invarg::make(); } if (tracker->get(s_id) != segment_state_t::CLOSED) { - ERROR("D{} S{} invalid state {} != CLOSED", - get_device_id(), s_id, tracker->get(s_id)); + ERROR("{} invalid state {} != CLOSED", id, tracker->get(s_id)); return crimson::ct_error::invarg::make(); } @@ -632,41 +619,37 @@ SegmentManager::read_ertr::future<> BlockSegmentManager::read( { LOG_PREFIX(BlockSegmentManager::read); auto& seg_addr = addr.as_seg_paddr(); - auto s_id = seg_addr.get_segment_id().device_segment_id(); + auto id = seg_addr.get_segment_id(); + auto s_id = id.device_segment_id(); auto s_off = seg_addr.get_segment_off(); auto p_off = get_offset(addr); - DEBUG("D{} S{} offset={}~{} poffset={} ...", - get_device_id(), s_id, s_off, len, p_off); + DEBUG("{} offset={}~{} poffset={} ...", id, s_off, len, p_off); assert(addr.get_device_id() == get_device_id()); if (s_off % superblock.block_size != 0 || len % superblock.block_size != 0) { - ERROR("D{} S{} offset={}~{} poffset={} invalid read", - get_device_id(), s_id, s_off, len, p_off); + ERROR("{} offset={}~{} poffset={} invalid read", id, s_off, len, p_off); return crimson::ct_error::invarg::make(); } if (s_id >= get_num_segments()) { - ERROR("D{} S{} offset={}~{} poffset={} segment-id out of range {}", - get_device_id(), s_id, s_off, len, p_off, - get_num_segments()); + ERROR("{} offset={}~{} poffset={} segment-id out of range {}", + id, s_off, len, p_off, get_num_segments()); return crimson::ct_error::invarg::make(); } if (s_off + len > superblock.segment_size) { - ERROR("D{} S{} offset={}~{} poffset={} read out of range {}", - get_device_id(), s_id, s_off, len, p_off, - superblock.segment_size); + ERROR("{} offset={}~{} poffset={} read out of range {}", + id, s_off, len, p_off, superblock.segment_size); return crimson::ct_error::invarg::make(); } if (tracker->get(s_id) == segment_state_t::EMPTY) { // XXX: not an error during scanning, // might need refactor to increase the log level - DEBUG("D{} S{} offset={}~{} poffset={} invalid state {}", - get_device_id(), s_id, s_off, len, p_off, - tracker->get(s_id)); + DEBUG("{} offset={}~{} poffset={} invalid state {}", + id, s_off, len, p_off, tracker->get(s_id)); return crimson::ct_error::enoent::make(); } @@ -682,7 +665,7 @@ SegmentManager::read_ertr::future<> BlockSegmentManager::read( void BlockSegmentManager::register_metrics() { LOG_PREFIX(BlockSegmentManager::register_metrics); - DEBUG("D{}", get_device_id()); + DEBUG("{}", device_id_printer_t{get_device_id()}); namespace sm = seastar::metrics; std::vector label_instances; label_instances.push_back(sm::label_instance("device_id", get_device_id())); -- 2.39.5