Ceph » CephFS

Saw this on a next test (http://qa-proxy.ceph.com/teuthology/sage-2014-12-01_11:11:17-fs-next-distro-basic-multi/628949/teuthology.log)

------------------------------------
existing dependency OSDSession (25) -> OSDSession::completion_lock (26) at:
 ceph version 0.88-234-g310a3f1 (310a3f1c65d25ee1fc60398f0fe025e4b19f55fe)
 1: (Objecter::handle_osd_op_reply(MOSDOpReply*)+0x12a8) [0x8083f8]
 2: (Objecter::ms_dispatch(Message*)+0x20b) [0x81480b]
 3: (Messenger::ms_deliver_dispatch(Message*)+0x77) [0xa135f7]
 4: (DispatchQueue::entry()+0x44a) [0xa23e9a]
 5: (DispatchQueue::DispatchThread::entry()+0xd) [0x924ecd]
 6: (()+0x7e9a) [0x7f8ab5d6ee9a]
 7: (clone()+0x6d) [0x7f8ab471dccd]

    -5> 2014-12-01 16:42:37.412717 7f8ab0c8e700  0 existing intermediate dependency Objecter::rwlock (23) -> OSDSession (25) at:
 ceph version 0.88-234-g310a3f1 (310a3f1c65d25ee1fc60398f0fe025e4b19f55fe)
 1: (Objecter::_scan_requests(Objecter::OSDSession*, bool, bool, std::map<unsigned long, Objecter::Op*, std::less<unsigned long>, std::allocator<std::pair<unsigned long const, Objecter::Op*> > >&, std::list<Objecter::LingerOp*, std::allocator<Objecter::LingerOp*> >&, std::map<unsigned long, Objecter::CommandOp*, std::less<unsigned long>, std::allocator<std::pair<unsigned long const, Objecter::CommandOp*> > >&)+0x99) [0x8057d9]
 2: (Objecter::handle_osd_map(MOSDMap*)+0x1f67) [0x80fa17]
 3: (Objecter::ms_dispatch(Message*)+0x257) [0x814857]
 4: (Messenger::ms_deliver_dispatch(Message*)+0x77) [0xa135f7]
 5: (DispatchQueue::entry()+0x44a) [0xa23e9a]
 6: (DispatchQueue::DispatchThread::entry()+0xd) [0x924ecd]
 7: (()+0x7e9a) [0x7f8ab5d6ee9a]
 8: (clone()+0x6d) [0x7f8ab471dccd]

    -4> 2014-12-01 16:42:37.412751 7f8ab0c8e700  0 new dependency OSDSession::completion_lock (26) -> Objecter::rwlock (23) creates a cycle at
 ceph version 0.88-234-g310a3f1 (310a3f1c65d25ee1fc60398f0fe025e4b19f55fe)
 1: (Context::complete(int)+0x9) [0x5b79a9]
 2: (Objecter::handle_osd_op_reply(MOSDOpReply*)+0x12dc) [0x80842c]
 3: (Objecter::ms_dispatch(Message*)+0x20b) [0x81480b]
 4: (Messenger::ms_deliver_dispatch(Message*)+0x77) [0xa135f7]
 5: (DispatchQueue::entry()+0x44a) [0xa23e9a]
 6: (DispatchQueue::DispatchThread::entry()+0xd) [0x924ecd]
 7: (()+0x7e9a) [0x7f8ab5d6ee9a]
 8: (clone()+0x6d) [0x7f8ab471dccd]

    -3> 2014-12-01 16:42:37.412764 7f8ab0c8e700  0 btw, i am holding these locks:
    -2> 2014-12-01 16:42:37.412765 7f8ab0c8e700  0   OSDSession::completion_lock (26)
    -1> 2014-12-01 16:42:37.412767 7f8ab0c8e700  0 

     0> 2014-12-01 16:42:37.414541 7f8ab0c8e700 -1 common/lockdep.cc: In function 'int lockdep_will_lock(const char*, int)' thread 7f8ab0c8e700 time 2014-12-01 16:42:37.412774
common/lockdep.cc: 225: FAILED assert(0)

 ceph version 0.88-234-g310a3f1 (310a3f1c65d25ee1fc60398f0fe025e4b19f55fe)
 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x7f) [0x93b5df]
 2: (lockdep_will_lock(char const*, int)+0xc50) [0x9be3e0]
 3: (Filer::_do_purge_range(PurgeRange*, int)+0x7a2) [0x7dbe12]
 4: (Context::complete(int)+0x9) [0x5b79a9]
 5: (Objecter::handle_osd_op_reply(MOSDOpReply*)+0x12dc) [0x80842c]
 6: (Objecter::ms_dispatch(Message*)+0x20b) [0x81480b]
 7: (Messenger::ms_deliver_dispatch(Message*)+0x77) [0xa135f7]
 8: (DispatchQueue::entry()+0x44a) [0xa23e9a]
 9: (DispatchQueue::DispatchThread::entry()+0xd) [0x924ecd]
 10: (()+0x7e9a) [0x7f8ab5d6ee9a]
 11: (clone()+0x6d) [0x7f8ab471dccd]
 NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

I'm not sure if this is something in the MDS or if the Objecter interface is a little broken, since it looks like we're somehow not allowed to grab osdmaps in Objecter completion contexts? Or maybe we're just not on a Finisher queue and should be.