https://tracker.ceph.com/
https://tracker.ceph.com/favicon.ico
2016-01-26T10:29:23Z
Ceph
rbd - Bug #14510: TestLibRBD.ObjectMapConsistentSnap librbd/Journal.cc: 376: FAILED assert(m_state == STATE_READY)
https://tracker.ceph.com/issues/14510?journal_id=64554
2016-01-26T10:29:23Z
Mykola Golub
mgolub@suse.com
<ul></ul><p>Below is a debug log for the crash. librbd::SnapshotCreateRequest may be called when the journal has not finished the initialization yet.</p>
<p>2016-01-26 12:07:43.873044 7fe7f1ce3100 0 lockdep start<br />2016-01-26 12:07:43.874851 7fe7f1ce3100 -1 WARNING: the following dangerous and experimental features are enabled: *<br />2016-01-26 12:07:43.876436 7fe7f1ce3100 -1 WARNING: the following dangerous and experimental features are enabled: *<br />2016-01-26 12:07:43.876512 7fe7f1ce3100 20 librbd: create 0x7fff933492b0 name = image1 size = 1048576 old_format = 0 features = 109 order = 12 stripe_unit = 0 stripe_count = 0<br />2016-01-26 12:07:43.876770 7fe7f1ce3100 -1 Failed to load class: .libs/libcls_hello.so: undefined symbol: _ZTI10PGLSFilter<br />2016-01-26 12:07:43.876955 7fe7f1ce3100 -1 Failed to load class: .libs/libcls_user.so: undefined symbol: _Z23cls_cxx_map_read_headerPvPN4ceph6buffer4listE<br />2016-01-26 12:07:43.877136 7fe7f1ce3100 -1 Failed to load class: .libs/libcls_version.so: undefined symbol: _Z19cls_gen_rand_base64Pci<br />2016-01-26 12:07:43.877178 7fe7f1ce3100 -1 Failed to load class: .libs/libcls_log.so: undefined symbol: _Z23cls_cxx_map_read_headerPvPN4ceph6buffer4listE<br />2016-01-26 12:07:43.878402 7fe7f1ce3100 -1 Failed to load class: .libs/libcls_rgw.so: undefined symbol: _Z23cls_cxx_map_read_headerPvPN4ceph6buffer4listE<br />2016-01-26 12:07:43.878542 7fe7f1ce3100 -1 Failed to load class: .libs/libcls_cephfs.so: undefined symbol: _ZTI10PGLSFilter<br />2016-01-26 12:07:43.879710 7fe7f1ce3100 -1 Failed to load class: .libs/libcls_refcount.so: undefined symbol: _Z14cls_cxx_removePv<br />2016-01-26 12:07:43.879775 7fe7f1ce3100 2 librbd: adding rbd image to directory...<br />2016-01-26 12:07:43.879902 7fe7f1ce3100 5 librbd::Journal: create: image=06a785fd<br />2016-01-26 12:07:43.879919 7fe7f1ce3100 5 Journaler: creating new journal: journal.06a785fd<br />2016-01-26 12:07:43.879955 7fe7f1ce3100 10 JournalMetadata: register_client: <br />2016-01-26 12:07:43.879985 7fe7f1ce3100 10 JournalMetadata: notifying journal header update<br />2016-01-26 12:07:43.888854 7fe7f1ce3100 2 librbd: done.<br />2016-01-26 12:07:43.888999 7fe7f1ce3100 5 librbd::AioImageRequestWQ: 0x7fe7fcc19010 : ictx=0x7fe7fcc1f310<br />2016-01-26 12:07:43.889021 7fe7f1ce3100 20 librbd::ImageState: open<br />2016-01-26 12:07:43.889023 7fe7f1ce3100 10 librbd::ImageState: 0x7fe7fcc1fd00 send_open<br />2016-01-26 12:07:43.889024 7fe7f1ce3100 10 librbd::image::OpenRequest: 0x7fe7fcc19a10 send_v2_detect_header<br />2016-01-26 12:07:43.889096 7fe7e10fa700 10 librbd::image::OpenRequest: handle_v2_detect_header: r=0<br />2016-01-26 12:07:43.889101 7fe7e10fa700 10 librbd::image::OpenRequest: 0x7fe7fcc19a10 send_v2_get_id<br />2016-01-26 12:07:43.889147 7fe7e10fa700 10 librbd::image::OpenRequest: handle_v2_get_id: r=0<br />2016-01-26 12:07:43.889150 7fe7e10fa700 10 librbd::image::OpenRequest: 0x7fe7fcc19a10 send_v2_get_immutable_metadata<br />2016-01-26 12:07:43.889192 7fe7e10fa700 10 librbd::image::OpenRequest: handle_v2_get_immutable_metadata: r=0<br />2016-01-26 12:07:43.889194 7fe7e10fa700 10 librbd::image::OpenRequest: 0x7fe7fcc19a10 send_v2_get_stripe_unit_count<br />2016-01-26 12:07:43.889225 7fe7e10fa700 10 librbd::image::OpenRequest: handle_v2_get_stripe_unit_count: r=-8<br />2016-01-26 12:07:43.889231 7fe7e10fa700 10 librbd::ImageCtx: init_layout stripe_unit 4096 stripe_count 1 object_size 4096 prefix rbd_data.06a785fd format rbd_data.06a785fd.%016llx<br />2016-01-26 12:07:43.889233 7fe7e10fa700 20 librbd::ImageCtx: apply_metadata_confs<br />2016-01-26 12:07:43.889307 7fe7e10fa700 20 librbd::ImageCtx: enabling caching...<br />2016-01-26 12:07:43.889310 7fe7e10fa700 20 librbd::ImageCtx: Initial cache settings: size=33554432 num_objects=10 max_dirty=0 target_dirty=16777216 max_dirty_age=1<br />2016-01-26 12:07:43.889358 7fe7e10fa700 10 librbd::ImageCtx: cache bytes 33554432 -> about 1048 objects<br />2016-01-26 12:07:43.889388 7fe7e10fa700 10 librbd::image::OpenRequest: 0x7fe7fcc19a10 send_register_watch<br />2016-01-26 12:07:43.889447 7fe7db7d6700 10 librbd::ImageWatcher: 0x7fe7c4000d90 registering image watcher<br />2016-01-26 12:07:43.889471 7fe7db7d6700 10 librbd::image::OpenRequest: 0x7fe7fcc19a10 handle_register_watch: r=0<br />2016-01-26 12:07:43.889472 7fe7db7d6700 10 librbd::image::OpenRequest: 0x7fe7fcc19a10 send_refresh<br />2016-01-26 12:07:43.889473 7fe7db7d6700 10 librbd::image::RefreshRequest: 0x7fe7c4002410 send_v2_get_mutable_metadata<br />2016-01-26 12:07:43.889532 7fe7e10fa700 10 librbd::image::RefreshRequest: 0x7fe7c4002410 handle_v2_get_mutable_metadata: r=0<br />2016-01-26 12:07:43.889535 7fe7e10fa700 10 librbd::image::RefreshRequest: 0x7fe7c4002410 send_v2_get_flags<br />2016-01-26 12:07:43.889555 7fe7e10fa700 10 librbd::image::RefreshRequest: 0x7fe7c4002410 handle_v2_get_flags: r=0<br />2016-01-26 12:07:43.889562 7fe7e10fa700 10 librbd::image::RefreshRequest: 0x7fe7c4002410 send_v2_init_exclusive_lock<br />2016-01-26 12:07:43.889567 7fe7e10fa700 10 librbd::ExclusiveLock: 0x7fe7bc003250 init<br />2016-01-26 12:07:43.889575 7fe7e10fa700 5 librbd::AioImageRequestWQ: block_writes: 0x7fe7fcc1f310, num=1<br />2016-01-26 12:07:43.889595 7fe7db7d6700 10 librbd::ExclusiveLock: 0x7fe7bc003250 handle_init_complete<br />2016-01-26 12:07:43.889598 7fe7db7d6700 10 librbd::image::RefreshRequest: 0x7fe7c4002410 handle_v2_init_exclusive_lock: r=0<br />2016-01-26 12:07:43.889599 7fe7db7d6700 20 librbd::image::RefreshRequest: 0x7fe7c4002410 apply<br />2016-01-26 12:07:43.889640 7fe7db7d6700 10 librbd::image::OpenRequest: handle_refresh: r=0<br />2016-01-26 12:07:43.889641 7fe7db7d6700 10 librbd::ImageState: 0x7fe7fcc1fd00 handle_open: r=0<br />2016-01-26 12:07:43.889815 7fe7d8fd1700 20 librbd: info 0x7fe7fcc1f310<br />2016-01-26 12:07:43.889818 7fe7f1ce3100 5 librbd::Operations: 0x7fe7fcbe15d0 snap_create: snap_name=snap0<br />2016-01-26 12:07:43.889970 7fe7d8fd1700 20 librbd::AioImageRequestWQ: write: ictx=0x7fe7fcc1f310, off=0, len = 3<br />2016-01-26 12:07:43.889976 7fe7d8fd1700 20 librbd::AioImageRequestWQ: aio_write: ictx=0x7fe7fcc1f310, completion=0x7fe7b0000d40, off=0, len=3, flags=0<br />2016-01-26 12:07:43.889978 7fe7d8fd1700 20 librbd::AioImageRequestWQ: queue: ictx=0x7fe7fcc1f310, req=0x7fe7b0000b60<br />2016-01-26 12:07:43.890028 7fe7d8fd1700 20 librbd::ExclusiveLock: 0x7fe7bc003250 is_lock_owner=0<br />2016-01-26 12:07:43.890031 7fe7d8fd1700 10 librbd::ExclusiveLock: 0x7fe7bc003250 request_lock<br />2016-01-26 12:07:43.890032 7fe7d8fd1700 10 librbd::ExclusiveLock: 0x7fe7bc003250 send_acquire_lock<br />2016-01-26 12:07:43.890073 7fe7d8fd1700 10 librbd::exclusive_lock::AcquireRequest: send_lock<br />2016-01-26 12:07:43.890118 7fe7e10fa700 10 librbd::exclusive_lock::AcquireRequest: handle_lock: r=0<br />2016-01-26 12:07:43.890120 7fe7e10fa700 10 librbd::exclusive_lock::AcquireRequest: send_open_object_map<br />2016-01-26 12:07:43.890123 7fe7e10fa700 10 librbd::object_map::RefreshRequest: 0x7fe7bc0039b0 send_load: oid=rbd_object_map.06a785fd<br />2016-01-26 12:07:43.890193 7fe7e10fa700 10 librbd::object_map::RefreshRequest: 0x7fe7bc0039b0 handle_load: r=0<br />2016-01-26 12:07:43.890201 7fe7e10fa700 20 librbd::object_map::RefreshRequest: refreshed object map: num_objs=256<br />2016-01-26 12:07:43.890204 7fe7e10fa700 10 librbd::exclusive_lock::AcquireRequest: handle_open_object_map: r=0<br />2016-01-26 12:07:43.890205 7fe7e10fa700 10 librbd::exclusive_lock::AcquireRequest: send_lock_object_map<br />2016-01-26 12:07:43.890206 7fe7e10fa700 10 librbd::object_map::LockRequest: 0x7fe7bc004550 send_lock: oid=rbd_object_map.06a785fd<br />2016-01-26 12:07:43.890331 7fe7e10fa700 10 librbd::object_map::LockRequest: 0x7fe7bc004550 handle_lock: r=0<br />2016-01-26 12:07:43.890334 7fe7e10fa700 10 librbd::exclusive_lock::AcquireRequest: handle_lock_object_map: r=0<br />2016-01-26 12:07:43.890335 7fe7e10fa700 10 librbd::ExclusiveLock: 0x7fe7bc003250 handle_acquiring_lock<br />2016-01-26 12:07:43.890337 7fe7e10fa700 10 librbd::exclusive_lock::AcquireRequest: send_open_journal<br />2016-01-26 12:07:43.890345 7fe7e10fa700 5 librbd::Journal: 0x7fe7bc005050: ictx=0x7fe7fcc1f310<br />2016-01-26 12:07:43.890346 7fe7e10fa700 20 librbd::Journal: 0x7fe7bc005050 open<br />2016-01-26 12:07:43.890348 7fe7e10fa700 20 librbd::Journal: 0x7fe7bc005050 wait_for_steady_state: on_state=0x7fe7bc0042c0<br />2016-01-26 12:07:43.890348 7fe7e10fa700 20 librbd::Journal: 0x7fe7bc005050 create_journaler<br />2016-01-26 12:07:43.890349 7fe7e10fa700 20 librbd::Journal: 0x7fe7bc005050 transition_state: new state=1<br />2016-01-26 12:07:43.890458 7fe7f1ce3100 20 librbd::ExclusiveLock: 0x7fe7bc003250 is_lock_owner=1<br />2016-01-26 12:07:43.890462 7fe7f1ce3100 20 librbd::ExclusiveLock: 0x7fe7bc003250 is_lock_owner=1<br />2016-01-26 12:07:43.890464 7fe7f1ce3100 20 librbd::ExclusiveLock: 0x7fe7bc003250 is_lock_owner=1<br />2016-01-26 12:07:43.890465 7fe7f1ce3100 5 librbd::Operations: 0x7fe7fcbe15d0 snap_create: snap_name=snap0<br />2016-01-26 12:07:43.890471 7fe7e10fa700 10 JournalMetadata: initialized immutable metadata<br />2016-01-26 12:07:43.890471 7fe7f1ce3100 5 librbd::SnapshotCreateRequest: 0x7fe7fcc1b640 send_suspend_requests<br />2016-01-26 12:07:43.890472 7fe7e10fa700 10 JournalMetadata: refreshing mutable metadata<br />2016-01-26 12:07:43.890472 7fe7f1ce3100 5 librbd::SnapshotCreateRequest: 0x7fe7fcc1b640 send_suspend_aio<br />2016-01-26 12:07:43.890474 7fe7f1ce3100 5 librbd::AioImageRequestWQ: block_writes: 0x7fe7fcc1f310, num=2<br />2016-01-26 12:07:43.890513 7fe7e10fa700 10 JournalMetadata: refreshed mutable metadata: r=0<br />2016-01-26 12:07:43.890515 7fe7e10fa700 20 Journaler: using image pool for journal data<br />2016-01-26 12:07:43.890617 7fe7db7d6700 5 librbd::SnapshotCreateRequest: 0x7fe7fcc1b640 handle_suspend_aio: r=0<br />2016-01-26 12:07:43.890678 7fe7db7d6700 10 librbd::Request: 0x7fe7fcc1b640 append_op_event</p>
rbd - Bug #14510: TestLibRBD.ObjectMapConsistentSnap librbd/Journal.cc: 376: FAILED assert(m_state == STATE_READY)
https://tracker.ceph.com/issues/14510?journal_id=64556
2016-01-26T14:56:47Z
Jason Dillaman
dillaman@redhat.com
<ul></ul><p>I think you have an old version of code -- "assert(m_state == STATE_READY)" doesn't exist in the codebase.</p>
rbd - Bug #14510: TestLibRBD.ObjectMapConsistentSnap librbd/Journal.cc: 376: FAILED assert(m_state == STATE_READY)
https://tracker.ceph.com/issues/14510?journal_id=64557
2016-01-26T14:57:02Z
Jason Dillaman
dillaman@redhat.com
<ul><li><strong>Status</strong> changed from <i>New</i> to <i>Need More Info</i></li></ul>
rbd - Bug #14510: TestLibRBD.ObjectMapConsistentSnap librbd/Journal.cc: 376: FAILED assert(m_state == STATE_READY)
https://tracker.ceph.com/issues/14510?journal_id=64558
2016-01-26T15:18:10Z
Mykola Golub
mgolub@suse.com
<ul></ul><p>I see it in today master: <a class="external" href="https://github.com/ceph/ceph/blob/master/src/librbd/Journal.cc#L376">https://github.com/ceph/ceph/blob/master/src/librbd/Journal.cc#L376</a></p>
rbd - Bug #14510: TestLibRBD.ObjectMapConsistentSnap librbd/Journal.cc: 376: FAILED assert(m_state == STATE_READY)
https://tracker.ceph.com/issues/14510?journal_id=64698
2016-01-27T17:58:22Z
Jason Dillaman
dillaman@redhat.com
<ul></ul><p>Whoops -- I was thinking this was a different issue I just fixed with Journal::handle_op_event_safe.</p>
rbd - Bug #14510: TestLibRBD.ObjectMapConsistentSnap librbd/Journal.cc: 376: FAILED assert(m_state == STATE_READY)
https://tracker.ceph.com/issues/14510?journal_id=64699
2016-01-27T17:58:31Z
Jason Dillaman
dillaman@redhat.com
<ul><li><strong>Status</strong> changed from <i>Need More Info</i> to <i>In Progress</i></li><li><strong>Assignee</strong> set to <i>Jason Dillaman</i></li></ul>
rbd - Bug #14510: TestLibRBD.ObjectMapConsistentSnap librbd/Journal.cc: 376: FAILED assert(m_state == STATE_READY)
https://tracker.ceph.com/issues/14510?journal_id=64705
2016-01-27T19:17:34Z
Jason Dillaman
dillaman@redhat.com
<ul><li><strong>Status</strong> changed from <i>In Progress</i> to <i>Fix Under Review</i></li></ul><p><strong>master PR</strong>: <a class="external" href="https://github.com/ceph/ceph/pull/7382">https://github.com/ceph/ceph/pull/7382</a></p>
rbd - Bug #14510: TestLibRBD.ObjectMapConsistentSnap librbd/Journal.cc: 376: FAILED assert(m_state == STATE_READY)
https://tracker.ceph.com/issues/14510?journal_id=64731
2016-01-28T02:11:08Z
Jason Dillaman
dillaman@redhat.com
<ul><li><strong>Status</strong> changed from <i>Fix Under Review</i> to <i>Resolved</i></li></ul>