From: Jason Dillaman Date: Wed, 18 Nov 2015 20:11:32 +0000 (-0500) Subject: librbd: improve debug output for object map state machines X-Git-Tag: v10.0.2~193^2~1 X-Git-Url: http://git-server-git.apps.pok.os.sepia.ceph.com/?a=commitdiff_plain;h=ac84faac75324ad10524e5bc4e4f4fbdabf8ab28;p=ceph.git librbd: improve debug output for object map state machines Signed-off-by: Jason Dillaman --- diff --git a/src/librbd/ObjectMap.cc b/src/librbd/ObjectMap.cc index 6c9ebc731708..469f4e74289a 100644 --- a/src/librbd/ObjectMap.cc +++ b/src/librbd/ObjectMap.cc @@ -86,7 +86,8 @@ int ObjectMap::lock() std::string oid(object_map_name(m_image_ctx.id, CEPH_NOSNAP)); while (true) { int r; - ldout(cct, 10) << &m_image_ctx << " locking object map" << dendl; + ldout(cct, 10) << &m_image_ctx << " locking object map: " + << oid << dendl; r = rados::cls::lock::lock(&m_image_ctx.md_ctx, oid, RBD_LOCK_NAME, LOCK_EXCLUSIVE, "", "", "", utime_t(), 0); @@ -140,9 +141,9 @@ int ObjectMap::unlock() return 0; } - ldout(m_image_ctx.cct, 10) << &m_image_ctx << " unlocking object map" - << dendl; std::string oid = object_map_name(m_image_ctx.id, CEPH_NOSNAP); + ldout(m_image_ctx.cct, 10) << &m_image_ctx << " unlocking object map: " + << oid << dendl; int r = rados::cls::lock::unlock(&m_image_ctx.md_ctx, oid, RBD_LOCK_NAME, ""); if (r < 0 && r != -ENOENT) { @@ -187,12 +188,13 @@ void ObjectMap::refresh(uint64_t snap_id) m_enabled = true; CephContext *cct = m_image_ctx.cct; - ldout(cct, 10) << &m_image_ctx << " refreshing object map" << dendl; + std::string oid(object_map_name(m_image_ctx.id, snap_id)); + ldout(cct, 10) << &m_image_ctx << " refreshing object map: " + << oid << dendl; uint64_t num_objs = Striper::get_num_objects( m_image_ctx.layout, m_image_ctx.get_image_size(snap_id)); - std::string oid(object_map_name(m_image_ctx.id, snap_id)); int r = cls_client::object_map_load(&m_image_ctx.md_ctx, oid, &m_object_map); if (r == -EINVAL) { @@ -223,7 +225,7 @@ void ObjectMap::refresh(uint64_t snap_id) return; } - ldout(cct, 20) << "refreshed object map: " << m_object_map.size() + ldout(cct, 20) << "refreshed object map: num_objs=" << m_object_map.size() << dendl; if (m_object_map.size() < num_objs) { diff --git a/src/librbd/object_map/ResizeRequest.cc b/src/librbd/object_map/ResizeRequest.cc index 8bdb64c4c6cc..afbde42f98b6 100644 --- a/src/librbd/object_map/ResizeRequest.cc +++ b/src/librbd/object_map/ResizeRequest.cc @@ -30,8 +30,9 @@ void ResizeRequest::send() { RWLock::WLocker l(m_image_ctx.object_map_lock); m_num_objs = Striper::get_num_objects(m_image_ctx.layout, m_new_size); + std::string oid(ObjectMap::object_map_name(m_image_ctx.id, m_snap_id)); ldout(cct, 5) << &m_image_ctx << " resizing on-disk object map: " - << m_num_objs << dendl; + << "oid=" << oid << ", num_objs=" << m_num_objs << dendl; librados::ObjectWriteOperation op; if (m_snap_id == CEPH_NOSNAP) { @@ -40,7 +41,6 @@ void ResizeRequest::send() { cls_client::object_map_resize(&op, m_num_objs, m_default_object_state); librados::AioCompletion *rados_completion = create_callback_completion(); - std::string oid(ObjectMap::object_map_name(m_image_ctx.id, m_snap_id)); int r = m_image_ctx.md_ctx.aio_operate(oid, rados_completion, &op); assert(r == 0); rados_completion->release(); diff --git a/src/librbd/object_map/SnapshotCreateRequest.cc b/src/librbd/object_map/SnapshotCreateRequest.cc index 9bf4a7913c65..abca0e21258a 100644 --- a/src/librbd/object_map/SnapshotCreateRequest.cc +++ b/src/librbd/object_map/SnapshotCreateRequest.cc @@ -80,14 +80,14 @@ void SnapshotCreateRequest::send_read_map() { assert(m_image_ctx.get_snap_info(m_snap_id) != NULL); CephContext *cct = m_image_ctx.cct; - ldout(cct, 5) << this << " " << __func__ << dendl; + std::string oid(ObjectMap::object_map_name(m_image_ctx.id, CEPH_NOSNAP)); + ldout(cct, 5) << this << " " << __func__ << ": oid=" << oid << dendl; m_state = STATE_READ_MAP; // IO is blocked due to the snapshot creation -- consistent to read from disk librados::ObjectReadOperation op; op.read(0, 0, NULL, NULL); - std::string oid(ObjectMap::object_map_name(m_image_ctx.id, CEPH_NOSNAP)); librados::AioCompletion *rados_completion = create_callback_completion(); int r = m_image_ctx.md_ctx.aio_operate(oid, rados_completion, &op, &m_read_bl); @@ -96,9 +96,8 @@ void SnapshotCreateRequest::send_read_map() { } void SnapshotCreateRequest::send_write_map() { - std::string snap_oid(ObjectMap::object_map_name(m_image_ctx.id, m_snap_id)); - CephContext *cct = m_image_ctx.cct; + std::string snap_oid(ObjectMap::object_map_name(m_image_ctx.id, m_snap_id)); ldout(cct, 5) << this << " " << __func__ << ": snap_oid=" << snap_oid << dendl; m_state = STATE_WRITE_MAP; @@ -119,14 +118,14 @@ bool SnapshotCreateRequest::send_add_snapshot() { } CephContext *cct = m_image_ctx.cct; - ldout(cct, 5) << this << " " << __func__ << dendl; + std::string oid(ObjectMap::object_map_name(m_image_ctx.id, CEPH_NOSNAP)); + ldout(cct, 5) << this << " " << __func__ << ": oid=" << oid << dendl; m_state = STATE_ADD_SNAPSHOT; librados::ObjectWriteOperation op; rados::cls::lock::assert_locked(&op, RBD_LOCK_NAME, LOCK_EXCLUSIVE, "", ""); cls_client::object_map_snap_add(&op); - std::string oid(ObjectMap::object_map_name(m_image_ctx.id, CEPH_NOSNAP)); librados::AioCompletion *rados_completion = create_callback_completion(); int r = m_image_ctx.md_ctx.aio_operate(oid, rados_completion, &op); assert(r == 0); diff --git a/src/librbd/object_map/SnapshotRemoveRequest.cc b/src/librbd/object_map/SnapshotRemoveRequest.cc index 679735f0f34e..b3b145e1a868 100644 --- a/src/librbd/object_map/SnapshotRemoveRequest.cc +++ b/src/librbd/object_map/SnapshotRemoveRequest.cc @@ -103,17 +103,19 @@ bool SnapshotRemoveRequest::should_complete(int r) { void SnapshotRemoveRequest::send_load_map() { CephContext *cct = m_image_ctx.cct; - ldout(cct, 5) << this << " " << __func__ << dendl; + std::string snap_oid(ObjectMap::object_map_name(m_image_ctx.id, m_snap_id)); + ldout(cct, 5) << this << " " << __func__ << ": snap_oid=" << snap_oid + << dendl; m_state = STATE_LOAD_MAP; - std::string snap_oid(ObjectMap::object_map_name(m_image_ctx.id, m_snap_id)); cls_client::object_map_load(&m_image_ctx.md_ctx, snap_oid, &m_snap_object_map, create_callback_context()); } void SnapshotRemoveRequest::send_remove_snapshot() { CephContext *cct = m_image_ctx.cct; - ldout(cct, 5) << this << " " << __func__ << dendl; + std::string oid(ObjectMap::object_map_name(m_image_ctx.id, m_next_snap_id)); + ldout(cct, 5) << this << " " << __func__ << ": oid=" << oid << dendl; m_state = STATE_REMOVE_SNAPSHOT; librados::ObjectWriteOperation op; @@ -122,7 +124,6 @@ void SnapshotRemoveRequest::send_remove_snapshot() { } cls_client::object_map_snap_remove(&op, m_snap_object_map); - std::string oid(ObjectMap::object_map_name(m_image_ctx.id, m_next_snap_id)); librados::AioCompletion *rados_completion = create_callback_completion(); int r = m_image_ctx.md_ctx.aio_operate(oid, rados_completion, &op); assert(r == 0); @@ -145,13 +146,13 @@ void SnapshotRemoveRequest::send_invalidate_next_map() { void SnapshotRemoveRequest::send_remove_map() { CephContext *cct = m_image_ctx.cct; - ldout(cct, 5) << this << " " << __func__ << dendl; + std::string oid(ObjectMap::object_map_name(m_image_ctx.id, m_snap_id)); + ldout(cct, 5) << this << " " << __func__ << ": oid=" << oid << dendl; m_state = STATE_REMOVE_MAP; librados::ObjectWriteOperation op; op.remove(); - std::string oid(ObjectMap::object_map_name(m_image_ctx.id, m_snap_id)); librados::AioCompletion *rados_completion = create_callback_completion(); int r = m_image_ctx.md_ctx.aio_operate(oid, rados_completion, &op); assert(r == 0); diff --git a/src/librbd/object_map/SnapshotRollbackRequest.cc b/src/librbd/object_map/SnapshotRollbackRequest.cc index 8f5625587eb5..20cf5e376a45 100644 --- a/src/librbd/object_map/SnapshotRollbackRequest.cc +++ b/src/librbd/object_map/SnapshotRollbackRequest.cc @@ -98,14 +98,15 @@ void SnapshotRollbackRequest::send_write_map() { RWLock::RLocker owner_locker(m_image_ctx.owner_lock); CephContext *cct = m_image_ctx.cct; - ldout(cct, 5) << this << " " << __func__ << dendl; + std::string snap_oid(ObjectMap::object_map_name(m_image_ctx.id, CEPH_NOSNAP)); + ldout(cct, 5) << this << " " << __func__ << ": snap_oid=" << snap_oid + << dendl; m_state = STATE_WRITE_MAP; librados::ObjectWriteOperation op; rados::cls::lock::assert_locked(&op, RBD_LOCK_NAME, LOCK_EXCLUSIVE, "", ""); op.write_full(m_read_bl); - std::string snap_oid(ObjectMap::object_map_name(m_image_ctx.id, CEPH_NOSNAP)); librados::AioCompletion *rados_completion = create_callback_completion(); int r = m_image_ctx.md_ctx.aio_operate(snap_oid, rados_completion, &op); assert(r == 0); diff --git a/src/librbd/object_map/UpdateRequest.cc b/src/librbd/object_map/UpdateRequest.cc index eef548828f82..fc651ab145ad 100644 --- a/src/librbd/object_map/UpdateRequest.cc +++ b/src/librbd/object_map/UpdateRequest.cc @@ -25,10 +25,9 @@ void UpdateRequest::send() { // safe to update in-memory state first without handling rollback since any // failures will invalidate the object map + std::string oid(ObjectMap::object_map_name(m_image_ctx.id, m_snap_id)); ldout(cct, 20) << &m_image_ctx << " updating object map" - << (m_snap_id != CEPH_NOSNAP ? - " snap " + stringify(m_snap_id) : std::string()) - << ": [" + << ": oid=" << oid << ", [" << m_start_object_no << "," << m_end_object_no << ") = " << (m_current_state ? stringify(static_cast(*m_current_state)) : "") @@ -57,7 +56,6 @@ void UpdateRequest::send() { m_new_state, m_current_state); librados::AioCompletion *rados_completion = create_callback_completion(); - std::string oid(ObjectMap::object_map_name(m_image_ctx.id, m_snap_id)); int r = m_image_ctx.md_ctx.aio_operate(oid, rados_completion, &op); assert(r == 0); rados_completion->release();