Ceph » CephFS

2011-09-30 17:03:43.524357 7fc876c37720 ceph version 0.34.commit: 2f039eeeb745622b866d80feda7afa055e15f6d6. process: cmds. pid: 2743
starting mds.3 at 0.0.0.0:6800/2743
2011-09-30 17:03:43.525680 7fc876c37720 mds-1.0 168 MDSCacheObject
2011-09-30 17:03:43.525739 7fc876c37720 mds-1.0 2144 CInode
2011-09-30 17:03:43.525750 7fc876c37720 mds-1.0 16 elist<>::item 7=112
2011-09-30 17:03:43.525770 7fc876c37720 mds-1.0 360 inode_t
2011-09-30 17:03:43.525781 7fc876c37720 mds-1.0 56 nest_info_t
2011-09-30 17:03:43.525791 7fc876c37720 mds-1.0 32 frag_info_t
2011-09-30 17:03:43.525808 7fc876c37720 mds-1.0 40 SimpleLock *5=200
2011-09-30 17:03:43.525818 7fc876c37720 mds-1.0 48 ScatterLock *3=144
2011-09-30 17:03:43.525830 7fc876c37720 mds-1.0 472 CDentry
2011-09-30 17:03:43.525839 7fc876c37720 mds-1.0 16 elist<>::item
2011-09-30 17:03:43.525853 7fc876c37720 mds-1.0 40 SimpleLock
2011-09-30 17:03:43.525863 7fc876c37720 mds-1.0 1016 CDir
2011-09-30 17:03:43.525878 7fc876c37720 mds-1.0 16 elist<>::item *2=32
2011-09-30 17:03:43.525888 7fc876c37720 mds-1.0 192 fnode_t
2011-09-30 17:03:43.525899 7fc876c37720 mds-1.0 56 nest_info_t *2
2011-09-30 17:03:43.525908 7fc876c37720 mds-1.0 32 frag_info_t *2
2011-09-30 17:03:43.525924 7fc876c37720 mds-1.0 168 Capability
2011-09-30 17:03:43.525934 7fc876c37720 mds-1.0 32 xlist<>::item *2=64
2011-09-30 17:03:43.526711 7fc876c36700 mds-1.0 MDS::ms_get_authorizer type=mon
2011-09-30 17:03:43.527077 7fc8733de700 mds-1.0 ms_handle_connect on 64.188.61.199:6789/0
2011-09-30 17:03:43.527950 7fc876c37720 mds-1.0 beacon_send up:boot seq 1 (currently up:boot)
2011-09-30 17:03:43.528087 7fc876c37720 mds-1.0 create_logger
2011-09-30 17:03:43.529158 7fc8733de700 mds-1.0 handle_mds_map epoch 229 from mon1
2011-09-30 17:03:43.529196 7fc8733de700 mds-1.0 my compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
2011-09-30 17:03:43.529205 7fc8733de700 mds-1.0 mdsmap compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
2011-09-30 17:03:43.529216 7fc8733de700 mds-1.-1 map says i am 64.188.61.200:6800/2743 mds-1.-1 state down:dne
2011-09-30 17:03:43.529222 7fc8733de700 mds-1.-1 not in map yet
2011-09-30 17:03:47.528244 7fc8722db700 mds-1.-1 beacon_send up:boot seq 2 (currently down:dne)
2011-09-30 17:03:47.829565 7fc8733de700 mds-1.-1 handle_mds_map epoch 230 from mon1
2011-09-30 17:03:47.829598 7fc8733de700 mds-1.-1 my compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
2011-09-30 17:03:47.829609 7fc8733de700 mds-1.-1 mdsmap compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
2011-09-30 17:03:47.829619 7fc8733de700 mds-1.0 map says i am 64.188.61.200:6800/2743 mds-1.0 state up:standby
2011-09-30 17:03:47.829624 7fc8733de700 mds-1.0 handle_mds_map standby
2011-09-30 17:03:48.105039 7fc8733de700 mds-1.0 handle_mds_map epoch 231 from mon1
2011-09-30 17:03:48.105071 7fc8733de700 mds-1.0 my compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
2011-09-30 17:03:48.105083 7fc8733de700 mds-1.0 mdsmap compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
2011-09-30 17:03:48.105093 7fc8733de700 mds0.21 map says i am 64.188.61.200:6800/2743 mds0.21 state up:starting
2011-09-30 17:03:48.105099 7fc8733de700 mds0.21 handle_mds_map i am now mds0.21
2011-09-30 17:03:48.105104 7fc8733de700 mds0.21 handle_mds_map state change up:standby --> up:starting
2011-09-30 17:03:48.105115 7fc8733de700 mds0.21 boot_start 1: opening inotable
2011-09-30 17:03:48.105124 7fc8733de700 mds0.inotable: load
2011-09-30 17:03:48.105200 7fc8733de700 mds0.21 boot_start 1: opening sessionmap
2011-09-30 17:03:48.105211 7fc8733de700 mds0.sessionmap load
2011-09-30 17:03:48.105255 7fc8733de700 mds0.21 boot_start 1: opening anchor table
2011-09-30 17:03:48.105263 7fc8733de700 mds0.anchortable: load
2011-09-30 17:03:48.105314 7fc8733de700 mds0.21 boot_start 1: opening snap table
2011-09-30 17:03:48.105322 7fc8733de700 mds0.snaptable: load
2011-09-30 17:03:48.105366 7fc8733de700 mds0.21 boot_start 1: opening mds log
2011-09-30 17:03:48.105375 7fc8733de700 mds0.log open discovering log bounds
2011-09-30 17:03:48.105409 7fc8733de700 mds0.bal check_targets have need want
2011-09-30 17:03:48.105420 7fc8733de700 mds0.bal rebalance done
2011-09-30 17:03:48.105428 7fc8733de700 mds0.cache show_subtrees - no subtrees
2011-09-30 17:03:48.105867 7fc871ada700 mds0.21 MDS::ms_get_authorizer type=osd
2011-09-30 17:03:48.105949 7fc8719d9700 mds0.21 MDS::ms_get_authorizer type=osd
2011-09-30 17:03:48.105985 7fc8717d7700 mds0.21 MDS::ms_get_authorizer type=osd
2011-09-30 17:03:48.106027 7fc8718d8700 mds0.21 MDS::ms_get_authorizer type=osd
2011-09-30 17:03:48.106230 7fc8733de700 mds0.21 ms_handle_connect on 64.188.61.203:6800/31576
2011-09-30 17:03:48.106251 7fc8733de700 mds0.21 ms_handle_connect on 64.188.61.202:6800/22352
2011-09-30 17:03:48.106448 7fc8733de700 mds0.21 ms_handle_connect on 64.188.61.204:6801/456
2011-09-30 17:03:48.106470 7fc8733de700 mds0.21 ms_handle_connect on 64.188.61.207:6800/14918
2011-09-30 17:03:48.107228 7fc8733de700 mds0.snaptable: load_2 got 41 bytes
2011-09-30 17:03:48.107243 7fc8733de700 mds0.snaptable: load_2 loaded v0
2011-09-30 17:03:48.107269 7fc8733de700 mds0.inotable: load_2 got 29 bytes
2011-09-30 17:03:48.107276 7fc8733de700 mds0.inotable: load_2 loaded v1409883
2011-09-30 17:03:48.107899 7fc8733de700 mds0.sessionmap dump
2011-09-30 17:03:48.107960 7fc8733de700 mds0.sessionmap _load_finish v 2819737, 4 sessions, 1861 bytes
2011-09-30 17:03:48.107968 7fc8733de700 mds0.sessionmap dump
2011-09-30 17:03:48.107982 7fc8733de700 mds0.sessionmap client5529 0x7fc86c00a290 state open completed prealloc_inos [10000114f56~3e8] used_ions []
2011-09-30 17:03:48.108017 7fc8733de700 mds0.sessionmap client5524 0x7fc86c00a6f0 state open completed 4616,4619,4622,4625,4628,4631,4634,4637,4640,4643,4646,4649,4652,4655,4658,4661,4664,4667,4670,4673,4676,4679,4682,4685,4688,4691,4694,4697,4700,4703,4706,4709,4712,4715,4718,4721,4724,4727,4730,4733,4736,4739,4742,4745,4748,4751,4754,4757,4760,4763,4766,4769,4772,4775,4778,4781,4784,4787,4790,4793,4796,4799,4802,4805,4808,4811,4814,4817,4820,4823,4826,4829,4832,4835,4838,4841,4844,4847,4850,4853,4856,4859,4862,4865,4868,4871,4874,4877,4880,4883,4886,4889,4892,4895,4898,4901,4904,4907,4910,4913,4916,4919,4922,4925,4928,4931,4934,4937,4940,4943,4946,4949,4952,4955,4958,4961,4964,4967,4970,4973,4976,4979,4982,4985,4988,4991,4994,4997,5000,5003,5006,5009,5012,5015,5018,5021,5024,5027,5028 prealloc_inos [1000011572a~3e7,10000115b12~1] used_ions []
2011-09-30 17:03:48.108030 7fc8733de700 mds0.sessionmap client5904 0x7fc86c00a4c0 state open completed prealloc_inos [10000158b18~3e8] used_ions []
2011-09-30 17:03:48.108036 7fc8733de700 mds0.sessionmap client5527 0x7fc86c00c110 state open completed prealloc_inos [] used_ions []
2011-09-30 17:03:48.108053 7fc8733de700 mds0.anchortable: load_2 got 152 bytes
2011-09-30 17:03:48.108060 7fc8733de700 mds0.anchortable: load_2 loaded v8
2011-09-30 17:03:48.108181 7fc8712d2700 mds0.21 MDS::ms_get_authorizer type=osd
2011-09-30 17:03:48.108487 7fc8733de700 mds0.21 ms_handle_connect on 64.188.61.201:6800/32106
2011-09-30 17:03:48.111477 7fc8710d0700 mds0.21 MDS::ms_get_authorizer type=osd
2011-09-30 17:03:48.111777 7fc8733de700 mds0.21 ms_handle_connect on 64.188.61.205:6800/10063
2011-09-30 17:03:48.112424 7fc8733de700 mds0.21 boot_start 2: loading/discovering base inodes
2011-09-30 17:03:48.112442 7fc8733de700 mds0.cache creating system inode with ino:100
2011-09-30 17:03:48.112492 7fc8733de700 mds0.cache.ino(100) fetch
2011-09-30 17:03:48.112604 7fc8733de700 mds0.cache creating system inode with ino:1
2011-09-30 17:03:48.112615 7fc8733de700 mds0.cache.ino(1) fetch
2011-09-30 17:03:48.113363 7fc8733de700 mds0.cache.ino(100) _fetched got 0 and 395
2011-09-30 17:03:48.113382 7fc8733de700 mds0.cache.ino(100) magic is 'ceph fs volume v011' (expecting 'ceph fs volume v011')
2011-09-30 17:03:48.113407 7fc8733de700 mds0.cache.ino(100) decode_snap_blob snaprealm(100 seq 1 lc 0 cr 0 cps 1 snaps={} 0x7fc86c008dd0)
2011-09-30 17:03:48.113449 7fc8733de700 mds0.cache.ino(100) _fetched [inode 100 [...2,head] ~mds0/ auth v5966 snaprealm=0x7fc86c008dd0 f(v0 11=1+10) n(v1678 rc2011-09-28 17:12:47.937573 b9537082174 a2 30152=1980+28172)/n(v0 11=1+10) (iversion lock) 0x7fc86c00c370]
2011-09-30 17:03:48.113468 7fc8733de700 mds0.cache.ino(1) _fetched got 0 and 425
2011-09-30 17:03:48.113475 7fc8733de700 mds0.cache.ino(1) magic is 'ceph fs volume v011' (expecting 'ceph fs volume v011')
2011-09-30 17:03:48.113486 7fc8733de700 mds0.cache.ino(1) decode_snap_blob snaprealm(1 seq 1 lc 0 cr 0 cps 1 snaps={} 0x7fc86c01e010)
2011-09-30 17:03:48.113500 7fc8733de700 mds0.cache.ino(1) _fetched [inode 1 [...2,head] / auth v1 snaprealm=0x7fc86c01e010 f(v0 1=0+1) n(v0 1=0+1) (iversion lock) 0x7fc86c00cbd0]
2011-09-30 17:03:48.113507 7fc8733de700 mds0.21 boot_start 3: positioning at end of old mds log
2011-09-30 17:03:48.113512 7fc8733de700 mds0.log append positioning at end
2011-09-30 17:03:48.113520 7fc8733de700 mds0.21 starting_done
2011-09-30 17:03:48.113526 7fc8733de700 mds0.21 request_state up:active
2011-09-30 17:03:48.113532 7fc8733de700 mds0.21 beacon_send up:active seq 3 (currently up:starting)
2011-09-30 17:03:48.113549 7fc8733de700 mds0.log start_new_segment at 46071543743
2011-09-30 17:03:48.113561 7fc8733de700 mds0.cache create_subtree_map 0 subtrees, 0 fullauth
2011-09-30 17:03:48.113566 7fc8733de700 mds0.cache show_subtrees - no subtrees
mds/MDCache.cc: In function 'ESubtreeMap MDCache::create_subtree_map()', in thread '0x7fc8733de700'
mds/MDCache.cc: 2235: FAILED assert(mydir)
ceph version 0.34 (commit:2f039eeeb745622b866d80feda7afa055e15f6d6)
1: (MDCache::create_subtree_map()+0x248) [0x58c658]
2: (MDLog::start_new_segment(Context*)+0x3c7) [0x6a85b7]
3: (MDS::starting_done()+0x56) [0x4aa716]
4: (MDS::boot_start(int, int)+0x58e) [0x4aadbe]
5: (Context::complete(int)+0xa) [0x49415a]
6: (C_Gather::sub_finish(Context*, int)+0x24a) [0x494dea]
7: (C_Gather::C_GatherSub::finish(int)+0x12) [0x494f42]
8: (CInode::_fetched(ceph::buffer::list&, ceph::buffer::list&, Context*)+0xcb8) [0x674e18]
9: (Context::complete(int)+0xa) [0x49415a]
10: (C_Gather::sub_finish(Context*, int)+0x24a) [0x494dea]
11: (C_Gather::C_GatherSub::finish(int)+0x12) [0x494f42]
12: (Objecter::handle_osd_op_reply(MOSDOpReply*)+0x8df) [0x6b5aaf]
13: (MDS::handle_core_message(Message*)+0x88f) [0x4af51f]
14: (MDS::_dispatch(Message*)+0x2c) [0x4af5bc]
15: (MDS::ms_dispatch(Message*)+0x71) [0x4b0e41]
16: (SimpleMessenger::dispatch_entry()+0x7f3) [0x70bc23]
17: (SimpleMessenger::DispatchThread::entry()+0x3c) [0x48f2ac]
18: (()+0x6914) [0x7fc876817914]
19: (clone()+0x6d) [0x7fc8754b440d]
ceph version 0.34 (commit:2f039eeeb745622b866d80feda7afa055e15f6d6)
1: (MDCache::create_subtree_map()+0x248) [0x58c658]
2: (MDLog::start_new_segment(Context*)+0x3c7) [0x6a85b7]
3: (MDS::starting_done()+0x56) [0x4aa716]
4: (MDS::boot_start(int, int)+0x58e) [0x4aadbe]
5: (Context::complete(int)+0xa) [0x49415a]
6: (C_Gather::sub_finish(Context*, int)+0x24a) [0x494dea]
7: (C_Gather::C_GatherSub::finish(int)+0x12) [0x494f42]
8: (CInode::_fetched(ceph::buffer::list&, ceph::buffer::list&, Context*)+0xcb8) [0x674e18]
9: (Context::complete(int)+0xa) [0x49415a]
10: (C_Gather::sub_finish(Context*, int)+0x24a) [0x494dea]
11: (C_Gather::C_GatherSub::finish(int)+0x12) [0x494f42]
12: (Objecter::handle_osd_op_reply(MOSDOpReply*)+0x8df) [0x6b5aaf]
13: (MDS::handle_core_message(Message*)+0x88f) [0x4af51f]
14: (MDS::_dispatch(Message*)+0x2c) [0x4af5bc]
15: (MDS::ms_dispatch(Message*)+0x71) [0x4b0e41]
16: (SimpleMessenger::dispatch_entry()+0x7f3) [0x70bc23]
17: (SimpleMessenger::DispatchThread::entry()+0x3c) [0x48f2ac]
18: (()+0x6914) [0x7fc876817914]
19: (clone()+0x6d) [0x7fc8754b440d]
terminate called after throwing an instance of 'ceph::FailedAssertion'

• Caught signal (Aborted) *
  in thread 0x7fc8733de700
  ceph version 0.34 (commit:2f039eeeb745622b866d80feda7afa055e15f6d6)
  1: cmds() [0x785b04]
  2: (()+0xf0e0) [0x7fc8768200e0]
  3: (gsignal()+0x35) [0x7fc875415045]
  4: (abort()+0x17f) [0x7fc8754162df]
  5: (_gnu_cxx::_verbose_terminate_handler()+0x115) [0x7fc875c9fe65]
  6: (()+0xca296) [0x7fc875c9e296]
  7: (()+0xca2c3) [0x7fc875c9e2c3]
  8: (()+0xca3ae) [0x7fc875c9e3ae]
  9: (ceph::__ceph_assert_fail(char const, char const*, int, char const*)+0x3c2) [0x7251a2]
  10: (MDCache::create_subtree_map()+0x248) [0x58c658]
  11: (MDLog::start_new_segment(Context*)+0x3c7) [0x6a85b7]
  12: (MDS::starting_done()+0x56) [0x4aa716]
  13: (MDS::boot_start(int, int)+0x58e) [0x4aadbe]
  14: (Context::complete(int)+0xa) [0x49415a]
  15: (C_Gather::sub_finish(Context*, int)+0x24a) [0x494dea]
  16: (C_Gather::C_GatherSub::finish(int)+0x12) [0x494f42]
  17: (CInode::_fetched(ceph::buffer::list&, ceph::buffer::list&, Context*)+0xcb8) [0x674e18]
  18: (Context::complete(int)+0xa) [0x49415a]
  19: (C_Gather::sub_finish(Context*, int)+0x24a) [0x494dea]
  20: (C_Gather::C_GatherSub::finish(int)+0x12) [0x494f42]
  21: (Objecter::handle_osd_op_reply(MOSDOpReply*)+0x8df) [0x6b5aaf]
  22: (MDS::handle_core_message(Message*)+0x88f) [0x4af51f]
  23: (MDS::_dispatch(Message*)+0x2c) [0x4af5bc]
  24: (MDS::ms_dispatch(Message*)+0x71) [0x4b0e41]
  25: (SimpleMessenger::dispatch_entry()+0x7f3) [0x70bc23]
  26: (SimpleMessenger::DispatchThread::entry()+0x3c) [0x48f2ac]
  27: (()+0x6914) [0x7fc876817914]
  28: (clone()+0x6d) [0x7fc8754b440d]
  Aborted