Bug #3553
closedMDS core dumped running 0.48.2argonaut
0%
Description
/var/ceph/ceph-mds.a.log shows mds 'comitting suicide':
2012-11-29 00:09:08.569400 7f38fa8b2700 1 mds.0.6 handle_mds_map state change up:standby --> up:creating
2012-11-29 00:09:08.569796 7f38fa8b2700 0 mds.0.cache creating system inode with ino:1
2012-11-29 00:09:08.569867 7f38fa8b2700 0 mds.0.cache creating system inode with ino:2
2012-11-29 00:09:08.570037 7f38fa8b2700 0 mds.0.cache creating system inode with ino:100
2012-11-29 00:09:08.570043 7f38fa8b2700 0 mds.0.cache creating system inode with ino:600
2012-11-29 00:09:08.570093 7f38fa8b2700 0 mds.0.cache creating system inode with ino:601
2012-11-29 00:09:08.570133 7f38fa8b2700 0 mds.0.cache creating system inode with ino:602
2012-11-29 00:09:08.570176 7f38fa8b2700 0 mds.0.cache creating system inode with ino:603
2012-11-29 00:09:08.570213 7f38fa8b2700 0 mds.0.cache creating system inode with ino:604
2012-11-29 00:09:08.577602 7f38fa8b2700 0 mds.0.cache creating system inode with ino:605
2012-11-29 00:09:08.577813 7f38fa8b2700 0 mds.0.cache creating system inode with ino:606
2012-11-29 00:09:08.578163 7f38fa8b2700 0 mds.0.cache creating system inode with ino:607
2012-11-29 00:09:08.593088 7f38fa8b2700 0 mds.0.cache creating system inode with ino:608
2012-11-29 00:09:08.593608 7f38fa8b2700 0 mds.0.cache creating system inode with ino:609
2012-11-29 00:09:08.594045 7f38fa8b2700 0 mds.0.cache creating system inode with ino:200
2012-11-29 00:09:08.596847 7f38fa8b2700 1 mds.0.cache handle_mds_failure mds.0 : recovery peers are
2012-11-29 00:09:08.597289 7f38fa8b2700 0 mds.0.6 ms_handle_connect on 10.1.10.21:6800/6621
2012-11-29 00:09:08.597594 7f38fa8b2700 0 mds.0.6 ms_handle_connect on 10.1.10.22:6803/1418
2012-11-29 00:09:08.597896 7f38fa8b2700 0 mds.0.6 ms_handle_connect on 10.1.10.21:6804/3310
2012-11-29 00:09:08.598213 7f38fa8b2700 0 mds.0.6 ms_handle_connect on 10.1.10.26:6803/15483
2012-11-29 00:09:08.602016 7f38fa8b2700 0 mds.0.6 ms_handle_connect on 10.1.10.26:6800/15105
2012-11-29 00:09:08.604531 7f38fa8b2700 -1 mds.0.journaler(rw) _prezeroed got (6) No such device or address
2012-11-29 00:09:08.604635 7f38fa8b2700 -1 mds.0.journaler(rw) handle_write_error (6) No such device or address
2012-11-29 00:09:08.604692 7f38fa8b2700 -1 mds.0.log unhandled error (6) No such device or address, shutting down...
2012-11-29 00:09:08.604753 7f38fa8b2700 1 mds.0.6 suicide. wanted down:dne, now up:creating
2012-11-29 00:09:08.608606 7f39005fd780 0 stopped.
I had run:
strace service ceph start mds.a
2012-11-29 00:08:50.688792 7f38fa8b2700 0 mds.-1.0 ms_handle_connect on 10.1.10.22:6789/0
2012-11-29 00:08:50.704239 7f38fa8b2700 1 mds.-1.0 handle_mds_map standby
...
2012-11-29 00:09:08.604753 7f38fa8b2700 1 mds.0.6 suicide. wanted down:dne, now up:creating
2012-11-29 00:09:08.608606 7f39005fd780 0 stopped.
- ceph mds dump
dumped mdsmap epoch 112
epoch 112
flags 0
created 2012-11-27 21:37:02.536700
modified 2012-11-29 00:10:13.581751
tableserver 0
root 0
session_timeout 60
session_autoclose 300
last_failure 0
last_failure_osd_epoch 122
compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
max_mds 1
in 0
up {0=5050}
failed
stopped
data_pools [0]
metadata_pool 1
5050: 10.1.10.21:6803/6909 'a' mds.0.6 up:creating seq 1 laggy since 2012-11-29 00:09:23.513234
- ceph mds stat
e125: 1/1/1 up {0=a=up:creating(laggy or crashed)}
- service ceph start mds.a
=== mds.a ===
Starting Ceph mds.a on ceph1...
starting mds.a at :/0
root@ceph1:/var/lib/ceph/mds/ceph-a# 2012-11-29 00:14:03.877182 7f5bb2889700 0 mds.-1.0 ms_handle_connect on 10.1.10.22:6789/0
2012-11-29 00:14:03.889854 7f5bb2889700 1 mds.-1.0 handle_mds_map standby
ceph mds stat
e127: 1/1/1 up {0=a=up:creating(laggy or crashed)}, 1 up:standby
- ceph mds stat
e127: 1/1/1 up {0=a=up:creating(laggy or crashed)}, 1 up:standby
- ceph mds stat
e127: 1/1/1 up {0=a=up:creating(laggy or crashed)}, 1 up:standby
- ceph mds stat
2012-11-29 00:14:13.872619 7f5bb2889700 1 mds.0.7 handle_mds_map i am now mds.0.7
2012-11-29 00:14:13.872621 7f5bb2889700 1 mds.0.7 handle_mds_map state change up:standby --> up:creating
2012-11-29 00:14:13.872966 7f5bb2889700 0 mds.0.cache creating system inode with ino:1
2012-11-29 00:14:13.873032 7f5bb2889700 0 mds.0.cache creating system inode with ino:2
2012-11-29 00:14:13.873234 7f5bb2889700 0 mds.0.cache creating system inode with ino:100
2012-11-29 00:14:13.873240 7f5bb2889700 0 mds.0.cache creating system inode with ino:600
2012-11-29 00:14:13.873281 7f5bb2889700 0 mds.0.cache creating system inode with ino:601
2012-11-29 00:14:13.873318 7f5bb2889700 0 mds.0.cache creating system inode with ino:602
2012-11-29 00:14:13.873352 7f5bb2889700 0 mds.0.cache creating system inode with ino:603
2012-11-29 00:14:13.873393 7f5bb2889700 0 mds.0.cache creating system inode with ino:604
2012-11-29 00:14:13.873453 7f5bb2889700 0 mds.0.cache creating system inode with ino:605
2012-11-29 00:14:13.873494 7f5bb2889700 0 mds.0.cache creating system inode with ino:606
2012-11-29 00:14:13.873529 7f5bb2889700 0 mds.0.cache creating system inode with ino:607
2012-11-29 00:14:13.873580 7f5bb2889700 0 mds.0.cache creating system inode with ino:608
2012-11-29 00:14:13.873614 7f5bb2889700 0 mds.0.cache creating system inode with ino:609
2012-11-29 00:14:13.873649 7f5bb2889700 0 mds.0.cache creating system inode with ino:200
2012-11-29 00:14:13.873829 7f5bb2889700 1 mds.0.cache handle_mds_failure mds.0 : recovery peers are
2012-11-29 00:14:13.889027 7f5bb2889700 0 mds.0.7 ms_handle_connect on 10.1.10.21:6804/3310
2012-11-29 00:14:13.892693 7f5bb2889700 0 mds.0.7 ms_handle_connect on 10.1.10.22:6803/1418
2012-11-29 00:14:13.893313 7f5bb2889700 0 mds.0.7 ms_handle_connect on 10.1.10.22:6800/31304
2012-11-29 00:14:13.896744 7f5bb2889700 0 mds.0.7 ms_handle_connect on 10.1.10.26:6800/15105
2012-11-29 00:14:13.901255 7f5bb2889700 -1 mds/MDSTable.cc: In function 'virtual void C_MT_Save::finish(int)' thread 7f5bb2889700 time 2012-11-29 00:14:13.900486
mds/MDSTable.cc: 39: FAILED assert(r >= 0)
and below is the full crash....
attached is the "objdump -rdS /usr/bin/ceph-mds"
- ceph mds stat2012-11-29 00:14:13.872619 7f5bb2889700 1 mds.0.7 handle_mds_map i am now mds.0.7
2012-11-29 00:14:13.872621 7f5bb2889700 1 mds.0.7 handle_mds_map state change up:standby --> up:creating
2012-11-29 00:14:13.872966 7f5bb2889700 0 mds.0.cache creating system inode with ino:1
2012-11-29 00:14:13.873032 7f5bb2889700 0 mds.0.cache creating system inode with ino:2
2012-11-29 00:14:13.873234 7f5bb2889700 0 mds.0.cache creating system inode with ino:100
2012-11-29 00:14:13.873240 7f5bb2889700 0 mds.0.cache creating system inode with ino:600
2012-11-29 00:14:13.873281 7f5bb2889700 0 mds.0.cache creating system inode with ino:601
2012-11-29 00:14:13.873318 7f5bb2889700 0 mds.0.cache creating system inode with ino:602
2012-11-29 00:14:13.873352 7f5bb2889700 0 mds.0.cache creating system inode with ino:603
2012-11-29 00:14:13.873393 7f5bb2889700 0 mds.0.cache creating system inode with ino:604
2012-11-29 00:14:13.873453 7f5bb2889700 0 mds.0.cache creating system inode with ino:605
2012-11-29 00:14:13.873494 7f5bb2889700 0 mds.0.cache creating system inode with ino:606
2012-11-29 00:14:13.873529 7f5bb2889700 0 mds.0.cache creating system inode with ino:607
2012-11-29 00:14:13.873580 7f5bb2889700 0 mds.0.cache creating system inode with ino:608
2012-11-29 00:14:13.873614 7f5bb2889700 0 mds.0.cache creating system inode with ino:609
2012-11-29 00:14:13.873649 7f5bb2889700 0 mds.0.cache creating system inode with ino:200
2012-11-29 00:14:13.873829 7f5bb2889700 1 mds.0.cache handle_mds_failure mds.0 : recovery peers are
2012-11-29 00:14:13.889027 7f5bb2889700 0 mds.0.7 ms_handle_connect on 10.1.10.21:6804/3310
2012-11-29 00:14:13.892693 7f5bb2889700 0 mds.0.7 ms_handle_connect on 10.1.10.22:6803/1418
2012-11-29 00:14:13.893313 7f5bb2889700 0 mds.0.7 ms_handle_connect on 10.1.10.22:6800/31304
2012-11-29 00:14:13.896744 7f5bb2889700 0 mds.0.7 ms_handle_connect on 10.1.10.26:6800/15105
2012-11-29 00:14:13.901255 7f5bb2889700 -1 mds/MDSTable.cc: In function 'virtual void C_MT_Save::finish(int)' thread 7f5bb2889700 time 2012-11-29 00:14:13.900486
mds/MDSTable.cc: 39: FAILED assert(r >= 0)ceph version 0.48.2argonaut (commit:3e02b2fad88c2a95d9c0c86878f10d1beb780bfe)
1: /usr/bin/ceph-mds() [0x668bb2]
2: (Objecter::handle_osd_op_reply(MOSDOpReply*)+0xe03) [0x6b6083]
3: (MDS::handle_core_message(Message*)+0xae8) [0x4c1708]
4: (MDS::_dispatch(Message*)+0x2f) [0x4c18cf]
5: (MDS::ms_dispatch(Message*)+0x1eb) [0x4c34ab]
6: (SimpleMessenger::DispatchQueue::entry()+0x903) [0x7579a3]
7: (SimpleMessenger::dispatch_entry()+0x24) [0x758744]
8: (SimpleMessenger::DispatchThread::entry()+0xd) [0x717a5d]
9: (()+0x7e9a) [0x7f5bb7c68e9a]
10: (clone()+0x6d) [0x7f5bb6b0c4bd]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
--- begin dump of recent events ---
193> 2012-11-29 00:14:03.868751 7f5bb85d4780 5 asok(0x2e8b000) register_command perfcounters_dump hook 0x2e80010 0.0.0.0:6803/7389 accepter.bind my_inst.addr is 0.0.0.0:6803/7389 need_addr=1
-192> 2012-11-29 00:14:03.868783 7f5bb85d4780 5 asok(0x2e8b000) register_command 1 hook 0x2e80010
-191> 2012-11-29 00:14:03.868797 7f5bb85d4780 5 asok(0x2e8b000) register_command perf dump hook 0x2e80010
-190> 2012-11-29 00:14:03.868813 7f5bb85d4780 5 asok(0x2e8b000) register_command perfcounters_schema hook 0x2e80010
-189> 2012-11-29 00:14:03.868824 7f5bb85d4780 5 asok(0x2e8b000) register_command 2 hook 0x2e80010
-188> 2012-11-29 00:14:03.868834 7f5bb85d4780 5 asok(0x2e8b000) register_command perf schema hook 0x2e80010
-187> 2012-11-29 00:14:03.868844 7f5bb85d4780 5 asok(0x2e8b000) register_command config show hook 0x2e80010
-186> 2012-11-29 00:14:03.868853 7f5bb85d4780 5 asok(0x2e8b000) register_command config set hook 0x2e80010
-185> 2012-11-29 00:14:03.868861 7f5bb85d4780 5 asok(0x2e8b000) register_command log flush hook 0x2e80010
-184> 2012-11-29 00:14:03.868869 7f5bb85d4780 5 asok(0x2e8b000) register_command log dump hook 0x2e80010
-183> 2012-11-29 00:14:03.868876 7f5bb85d4780 5 asok(0x2e8b000) register_command log reopen hook 0x2e80010
-182> 2012-11-29 00:14:03.869659 7f5bb85d4780 0 ceph version 0.48.2argonaut (commit:3e02b2fad88c2a95d9c0c86878f10d1beb780bfe), process ceph-mds, pid 7389
-181> 2012-11-29 00:14:03.869895 7f5bb85d4780 1 -
180> 2012-11-29 00:14:03.872243 7f5bb85d4780 1 finished global_init_daemonize 0.0.0.0:6803/7389 messenger.start
-179> 2012-11-29 00:14:03.873959 7f5bb85d4780 5 asok(0x2e8b000) init /var/run/ceph/ceph-mds.a.asok
-178> 2012-11-29 00:14:03.873972 7f5bb85d4780 5 asok(0x2e8b000) bind_and_listen /var/run/ceph/ceph-mds.a.asok
-177> 2012-11-29 00:14:03.873993 7f5bb85d4780 5 asok(0x2e8b000) register_command 0 hook 0x2e7f0a8
-176> 2012-11-29 00:14:03.873998 7f5bb85d4780 5 asok(0x2e8b000) register_command version hook 0x2e7f0a8
-175> 2012-11-29 00:14:03.874001 7f5bb85d4780 5 asok(0x2e8b000) register_command git_version hook 0x2e7f0a8
-174> 2012-11-29 00:14:03.874003 7f5bb85d4780 5 asok(0x2e8b000) register_command help hook 0x2e800c0
-173> 2012-11-29 00:14:03.874074 7f5bb85d4780 1 -
193> 2012-11-29 00:14:03.874084 7f5bb85d4780 1 - 0.0.0.0:6803/7389 accepter.start
192> 2012-11-29 00:14:03.874234 7f5bb85d4780 2 auth: CephX auth is not supported. 0.0.0.0:6803/7389 --> 10.1.10.22:6789/0 -- auth(proto 0 26 bytes epoch 0) v1 -- ?+0 0x2e90e00 con 0x2ebd280
-191> 2012-11-29 00:14:03.874326 7f5bb85d4780 1 -
190> 2012-11-29 00:14:03.876323 7f5bb488d700 5 asok(0x2e8b000) entry start 10.1.10.21:6803/7389 learned my addr 10.1.10.21:6803/7389
-189> 2012-11-29 00:14:03.876824 7f5bb1086700 1 -
188> 2012-11-29 00:14:03.877182 7f5bb2889700 0 mds.-1.0 ms_handle_connect on 10.1.10.22:6789/0 10.1.10.21:6803/7389 <== mon.1 10.1.10.22:6789/0 1 ==== mon_map v1 ==== 473+0+0 (1810473923 0 0) 0x2ec0400 con 0x2ebd280
-187> 2012-11-29 00:14:03.879827 7f5bb85d2700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 473 (0 -> 473)
-186> 2012-11-29 00:14:03.880136 7f5bb2889700 1 -
185> 2012-11-29 00:14:03.880167 7f5bb2889700 1 monclient(hunting): found mon.c 10.1.10.21:6803/7389 <== mon.1 10.1.10.22:6789/0 2 ==== auth_reply(proto 1 0 Success) v1 ==== 24+0+0 (1089245616 0 0) 0x2ec0200 con 0x2ebd280
-184> 2012-11-29 00:14:03.880173 7f5bb2889700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) put 473 (0xaab328 -> 0)
-183> 2012-11-29 00:14:03.880210 7f5bb85d2700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 24 (0 -> 24)
-182> 2012-11-29 00:14:03.880273 7f5bb2889700 1 -
181> 2012-11-29 00:14:03.880302 7f5bb2889700 1 - 10.1.10.21:6803/7389 --> 10.1.10.22:6789/0 -- mon_subscribe({monmap=0+}) v2 -- ?+0 0x2ea31c0 con 0x2ebd280
180> 2012-11-29 00:14:03.880356 7f5bb2889700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) put 24 (0xaab328 -> 0) 10.1.10.21:6803/7389 --> 10.1.10.22:6789/0 -- mdsbeacon(5053/a up:boot seq 1 v0) v2 -- ?+0 0x2ebc500 con 0x2ebd280
-179> 2012-11-29 00:14:03.880375 7f5bb85d4780 5 monclient: authenticate success, global_id 5053
-178> 2012-11-29 00:14:03.880425 7f5bb85d4780 1 -
177> 2012-11-29 00:14:03.880444 7f5bb85d4780 5 asok(0x2e8b000) register_command objecter_requests hook 0x2e80100 10.1.10.21:6803/7389 --> 10.1.10.22:6789/0 -- mon_subscribe({monmap=2+,osdmap=0}) v2 -- ?+0 0x2ea38c0 con 0x2ebd280
-176> 2012-11-29 00:14:03.880456 7f5bb85d4780 1 -
175> 2012-11-29 00:14:03.880465 7f5bb85d4780 1 - 10.1.10.21:6803/7389 --> 10.1.10.22:6789/0 -- mon_subscribe({mdsmap=0+,monmap=2+,osdmap=0}) v2 -- ?+0 0x2ea3700 con 0x2ebd280
174> 2012-11-29 00:14:03.884484 7f5bb85d2700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 473 (0 -> 473) 10.1.10.21:6803/7389 <== mon.1 10.1.10.22:6789/0 3 ==== mon_map v1 ==== 473+0+0 (1810473923 0 0) 0x2ec0c00 con 0x2ebd280
-173> 2012-11-29 00:14:03.884525 7f5bb2889700 1 -
172> 2012-11-29 00:14:03.884543 7f5bb2889700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) put 473 (0xaab328 -> 0) 10.1.10.21:6803/7389 <== mon.1 10.1.10.22:6789/0 4 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0 (3361640162 0 0) 0x2ea31c0 con 0x2ebd280
-171> 2012-11-29 00:14:03.884555 7f5bb85d2700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 20 (0 -> 20)
-170> 2012-11-29 00:14:03.884580 7f5bb2889700 1 -
169> 2012-11-29 00:14:03.884589 7f5bb2889700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) put 20 (0xaab328 -> 0) 10.1.10.21:6803/7389 <== mon.1 10.1.10.22:6789/0 5 ==== osd_map(123..123 src has 1..123) v3 ==== 4423+0+0 (2572857167 0 0) 0x2ec0c00 con 0x2ebd280
-168> 2012-11-29 00:14:03.884599 7f5bb85d2700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 4423 (0 -> 4423)
-167> 2012-11-29 00:14:03.884641 7f5bb2889700 1 -
166> 2012-11-29 00:14:03.884722 7f5bb2889700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) put 4423 (0xaab328 -> 0) 10.1.10.21:6803/7389 <== mon.1 10.1.10.22:6789/0 6 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0 (3361640162 0 0) 0x2ea3a80 con 0x2ebd280
-165> 2012-11-29 00:14:03.884736 7f5bb85d2700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 20 (0 -> 20)
-164> 2012-11-29 00:14:03.884754 7f5bb2889700 1 -
163> 2012-11-29 00:14:03.884762 7f5bb2889700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) put 20 (0xaab328 -> 0) 10.1.10.21:6803/7389 <== mon.1 10.1.10.22:6789/0 7 ==== mdsmap(e 126) v1 ==== 535+0+0 (4058266551 0 0) 0x2ec0e00 con 0x2ebd280
-162> 2012-11-29 00:14:03.884771 7f5bb85d2700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 535 (0 -> 535)
-161> 2012-11-29 00:14:03.884793 7f5bb2889700 1 -
160> 2012-11-29 00:14:03.884803 7f5bb2889700 5 mds.-1.0 handle_mds_map epoch 126 from mon.1 10.1.10.21:6803/7389 <== mon.1 10.1.10.22:6789/0 8 ==== osd_map(123..123 src has 1..123) v3 ==== 4423+0+0 (2572857167 0 0) 0x2ec0200 con 0x2ebd280
-159> 2012-11-29 00:14:03.884818 7f5bb2889700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) put 535 (0xaab328 -> 0)
-158> 2012-11-29 00:14:03.884829 7f5bb85d2700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 4423 (0 -> 4423)
-157> 2012-11-29 00:14:03.884852 7f5bb2889700 1 -
156> 2012-11-29 00:14:03.884862 7f5bb2889700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) put 4423 (0xaab328 -> 0) 10.1.10.21:6803/7389 <== mon.1 10.1.10.22:6789/0 9 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0 (3361640162 0 0) 0x2ea38c0 con 0x2ebd280
-155> 2012-11-29 00:14:03.884877 7f5bb85d2700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 20 (0 -> 20)
-154> 2012-11-29 00:14:03.884946 7f5bb2889700 1 -
153> 2012-11-29 00:14:03.884955 7f5bb2889700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) put 20 (0xaab328 -> 0) 10.1.10.21:6803/7389 <== mon.1 10.1.10.22:6789/0 10 ==== mdsmap(e 127) v1 ==== 733+0+0 (941466860 0 0) 0x2ecb800 con 0x2ebd280
-152> 2012-11-29 00:14:03.889781 7f5bb85d2700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 733 (0 -> 733)
-151> 2012-11-29 00:14:03.889828 7f5bb2889700 1 -
150> 2012-11-29 00:14:03.889839 7f5bb2889700 5 mds.-1.-1 handle_mds_map epoch 127 from mon.1 10.1.10.21:6803/7389 --> 10.1.10.22:6789/0 -- mdsbeacon(5053/a up:standby seq 2 v127) v2 -- ?+0 0x2ebc780 con 0x2ebd280
-149> 2012-11-29 00:14:03.889854 7f5bb2889700 1 mds.-1.0 handle_mds_map standby
-148> 2012-11-29 00:14:03.889859 7f5bb2889700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) put 733 (0xaab328 -> 0)
-147> 2012-11-29 00:14:07.884413 7f5bb0f85700 1 -
146> 2012-11-29 00:14:07.888124 7f5bb85d2700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 103 (0 -> 103) 10.1.10.21:6803/7389 <== mon.1 10.1.10.22:6789/0 11 ==== mdsbeacon(5053/a up:standby seq 2 v127) v2 ==== 103+0+0 (3207107670 0 0) 0x2ebc500 con 0x2ebd280
-145> 2012-11-29 00:14:07.888193 7f5bb2889700 1 -
144> 2012-11-29 00:14:07.888229 7f5bb2889700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) put 103 (0xaab328 -> 0) 10.1.10.21:6803/7389 --> 10.1.10.22:6789/0 -- mdsbeacon(5053/a up:standby seq 3 v127) v2 -- ?+0 0x2ebca00 con 0x2ebd280
-143> 2012-11-29 00:14:11.888557 7f5bb0f85700 1 -
142> 2012-11-29 00:14:11.896688 7f5bb85d2700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 103 (0 -> 103) 10.1.10.21:6803/7389 <== mon.1 10.1.10.22:6789/0 12 ==== mdsbeacon(5053/a up:standby seq 3 v127) v2 ==== 103+0+0 (3322014001 0 0) 0x2ebcc80 con 0x2ebd280
-141> 2012-11-29 00:14:11.896911 7f5bb2889700 1 -
140> 2012-11-29 00:14:11.896949 7f5bb2889700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) put 103 (0xaab328 -> 0) 10.1.10.21:6803/7389 <== mon.1 10.1.10.22:6789/0 13 ==== mdsmap(e 128) v1 ==== 535+0+0 (1993446896 0 0) 0x2ecb600 con 0x2ebd280
-139> 2012-11-29 00:14:13.872525 7f5bb85d2700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 535 (0 -> 535)
-138> 2012-11-29 00:14:13.872576 7f5bb2889700 1 -
137> 2012-11-29 00:14:13.872592 7f5bb2889700 5 mds.-1.0 handle_mds_map epoch 128 from mon.1 10.1.10.21:6803/7389 mark_down 10.1.10.21:6803/6909 -- pipe dne
-136> 2012-11-29 00:14:13.872615 7f5bb2889700 1 -
135> 2012-11-29 00:14:13.872619 7f5bb2889700 1 mds.0.7 handle_mds_map i am now mds.0.7> up:creating
-134> 2012-11-29 00:14:13.872621 7f5bb2889700 1 mds.0.7 handle_mds_map state change up:standby -
133> 2012-11-29 00:14:13.872623 7f5bb2889700 3 mds.0.7 boot_create 10.1.10.21:6803/7389 --> 10.1.10.26:6803/15483 -- osd_op(mds.0.7:1 200.00000000 [writefull 0~84] 1.844f3494) v4 -- ?+0 0x2ec8000 con 0x2ebdb40
-132> 2012-11-29 00:14:13.872630 7f5bb2889700 5 mds.0.log create empty log
-131> 2012-11-29 00:14:13.872636 7f5bb2889700 1 mds.0.journaler(ro) set_writeable
-130> 2012-11-29 00:14:13.872637 7f5bb2889700 1 mds.0.journaler(rw) create blank journal
-129> 2012-11-29 00:14:13.872664 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 84
-128> 2012-11-29 00:14:13.872666 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-127> 2012-11-29 00:14:13.872740 7f5bb2889700 1 -
126> 2012-11-29 00:14:13.872776 7f5bb2889700 5 mds.0.log submit_entry 4194304~127 : ESubtreeMap 0 subtrees , 0 ambiguous [metablob] 10.1.10.21:6803/7389 --> 10.1.10.26:6803/15483 -- osd_op(mds.0.7:2 200.00000001 [delete] 1.6e5f474) v4 -- ?+0 0x2ec8b40 con 0x2ebdb40
-125> 2012-11-29 00:14:13.872802 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 0
-124> 2012-11-29 00:14:13.872803 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-123> 2012-11-29 00:14:13.872808 7f5bb2889700 1 -
122> 2012-11-29 00:14:13.872815 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 0 10.1.10.21:6803/7389 --> 10.1.10.26:6803/15483 -- osd_op(mds.0.7:3 200.00000002 [delete] 1.eb272dbb) v4 -- ?+0 0x2ed4480 con 0x2ebdb40
-121> 2012-11-29 00:14:13.872816 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-120> 2012-11-29 00:14:13.872822 7f5bb2889700 1 -
119> 2012-11-29 00:14:13.872829 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 0 10.1.10.21:6803/7389 --> 10.1.10.21:6804/3310 -- osd_op(mds.0.7:4 200.00000003 [delete] 1.95e3ab) v4 -- ?+0 0x2ed4240 con 0x2ebdc80
-118> 2012-11-29 00:14:13.872833 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-117> 2012-11-29 00:14:13.872861 7f5bb2889700 1 -
116> 2012-11-29 00:14:13.872872 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 0 10.1.10.21:6803/7389 --> 10.1.10.26:6800/15105 -- osd_op(mds.0.7:5 200.00000004 [delete] 1.1ba6bc1f) v4 -- ?+0 0x2ed4000 con 0x2ed6140
-115> 2012-11-29 00:14:13.872873 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-114> 2012-11-29 00:14:13.872899 7f5bb2889700 1 -
113> 2012-11-29 00:14:13.872915 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 0 10.1.10.21:6803/7389 --> 10.1.10.21:6800/6621 -- osd_op(mds.0.7:6 200.00000005 [delete] 1.96d5827a) v4 -- ?+0 0x2ed4d80 con 0x2ed68c0
-112> 2012-11-29 00:14:13.872916 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-111> 2012-11-29 00:14:13.872941 7f5bb2889700 1 -
110> 2012-11-29 00:14:13.872951 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 0 10.1.10.21:6803/7389 --> 10.1.10.26:6800/15105 -- osd_op(mds.0.7:7 200.00000006 [delete] 1.ade7efde) v4 -- ?+0 0x2ed4b40 con 0x2ed6140
-109> 2012-11-29 00:14:13.872952 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-108> 2012-11-29 00:14:13.872955 7f5bb2889700 1 -
107> 2012-11-29 00:14:13.872960 7f5bb2889700 3 mds.0.7 boot_create creating fresh hierarchy 10.1.10.21:6803/7389 --> 10.1.10.26:6800/15105 -- osd_op(mds.0.7:8 2.00000000 [setxattr path (6),setxattr parent (38),tmapup 0~0] 1.96f33707) v4 -- ?+0 0x2ed46c0 con 0x2ed6140
-106> 2012-11-29 00:14:13.872966 7f5bb2889700 0 mds.0.cache creating system inode with ino:1
-105> 2012-11-29 00:14:13.873032 7f5bb2889700 0 mds.0.cache creating system inode with ino:2
-104> 2012-11-29 00:14:13.873142 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 256
-103> 2012-11-29 00:14:13.873145 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-102> 2012-11-29 00:14:13.873149 7f5bb2889700 1 -
101> 2012-11-29 00:14:13.873190 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 580 10.1.10.21:6803/7389 --> 10.1.10.21:6804/3310 -- osd_op(mds.0.7:9 1.00000000 [setxattr path,setxattr parent (13),tmapput 0~557] 1.6b2cdaff) v4 -- ?+0 0x2f06900 con 0x2ebdc80
-100> 2012-11-29 00:14:13.873192 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-99> 2012-11-29 00:14:13.873200 7f5bb2889700 1 -
98> 2012-11-29 00:14:13.873219 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 428 10.1.10.21:6803/7389 --> 10.1.10.26:6803/15483 -- osd_op(mds.0.7:10 1.00000000.inode [writefull 0~428] 1.232c0e14) v4 -- ?+0 0x2f066c0 con 0x2ebdb40
-97> 2012-11-29 00:14:13.873220 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-96> 2012-11-29 00:14:13.873225 7f5bb2889700 1 -
95> 2012-11-29 00:14:13.873231 7f5bb2889700 3 mds.0.7 boot_create creating mydir hierarchy 10.1.10.21:6803/7389 --> 10.1.10.21:6800/6621 -- osd_op(mds.0.7:11 600.00000000 [setxattr path (12),setxattr parent (39),tmapup 0~0] 1.c2e541b0) v4 -- ?+0 0x2f06000 con 0x2ed68c0
-94> 2012-11-29 00:14:13.873234 7f5bb2889700 0 mds.0.cache creating system inode with ino:100
-93> 2012-11-29 00:14:13.873240 7f5bb2889700 0 mds.0.cache creating system inode with ino:600
-92> 2012-11-29 00:14:13.873268 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 263
-91> 2012-11-29 00:14:13.873270 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-90> 2012-11-29 00:14:13.873273 7f5bb2889700 1 -
89> 2012-11-29 00:14:13.873281 7f5bb2889700 0 mds.0.cache creating system inode with ino:601 10.1.10.21:6803/7389 --> 10.1.10.21:6804/3310 -- osd_op(mds.0.7:12 601.00000000 [setxattr path (12),setxattr parent (39),tmapup 0~0] 1.81580290) v4 -- ?+0 0x2f06d80 con 0x2ebdc80
-88> 2012-11-29 00:14:13.873306 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 263
-87> 2012-11-29 00:14:13.873308 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-86> 2012-11-29 00:14:13.873312 7f5bb2889700 1 -
85> 2012-11-29 00:14:13.873318 7f5bb2889700 0 mds.0.cache creating system inode with ino:602 10.1.10.21:6803/7389 --> 10.1.10.21:6804/3310 -- osd_op(mds.0.7:13 602.00000000 [setxattr path (12),setxattr parent (39),tmapup 0~0] 1.2a8b6bd0) v4 -- ?+0 0x2f06b40 con 0x2ebdc80
-84> 2012-11-29 00:14:13.873340 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 263
-83> 2012-11-29 00:14:13.873342 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-82> 2012-11-29 00:14:13.873345 7f5bb2889700 1 -
81> 2012-11-29 00:14:13.873352 7f5bb2889700 0 mds.0.cache creating system inode with ino:603 10.1.10.21:6803/7389 --> 10.1.10.21:6800/6621 -- osd_op(mds.0.7:14 603.00000000 [setxattr path (12),setxattr parent (39),tmapup 0~0] 1.7a4d91b0) v4 -- ?+0 0x2f28d80 con 0x2ed68c0
-80> 2012-11-29 00:14:13.873378 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 263
-79> 2012-11-29 00:14:13.873379 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-78> 2012-11-29 00:14:13.873386 7f5bb2889700 1 -
77> 2012-11-29 00:14:13.873393 7f5bb2889700 0 mds.0.cache creating system inode with ino:604 10.1.10.21:6803/7389 --> 10.1.10.22:6803/1418 -- osd_op(mds.0.7:15 604.00000000 [setxattr path (12),setxattr parent (39),tmapup 0~0] 1.43e85c95) v4 -- ?+0 0x2f28b40 con 0x2ed6500
-76> 2012-11-29 00:14:13.873413 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 263
-75> 2012-11-29 00:14:13.873415 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-74> 2012-11-29 00:14:13.873443 7f5bb2889700 1 -
73> 2012-11-29 00:14:13.873453 7f5bb2889700 0 mds.0.cache creating system inode with ino:605 10.1.10.21:6803/7389 --> 10.1.10.21:6800/6621 -- osd_op(mds.0.7:16 605.00000000 [setxattr path (12),setxattr parent (39),tmapup 0~0] 1.d0c18e1d) v4 -- ?+0 0x2f28900 con 0x2ed68c0
-72> 2012-11-29 00:14:13.873482 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 263
-71> 2012-11-29 00:14:13.873483 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-70> 2012-11-29 00:14:13.873487 7f5bb2889700 1 -
69> 2012-11-29 00:14:13.873494 7f5bb2889700 0 mds.0.cache creating system inode with ino:606 10.1.10.21:6803/7389 --> 10.1.10.26:6803/15483 -- osd_op(mds.0.7:17 606.00000000 [setxattr path (12),setxattr parent (39),tmapup 0~0] 1.f89eaaf4) v4 -- ?+0 0x2f286c0 con 0x2ebdb40
-68> 2012-11-29 00:14:13.873514 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 263
-67> 2012-11-29 00:14:13.873515 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-66> 2012-11-29 00:14:13.873522 7f5bb2889700 1 -
65> 2012-11-29 00:14:13.873529 7f5bb2889700 0 mds.0.cache creating system inode with ino:607 10.1.10.21:6803/7389 --> 10.1.10.21:6800/6621 -- osd_op(mds.0.7:18 607.00000000 [setxattr path (12),setxattr parent (39),tmapup 0~0] 1.bb590b7c) v4 -- ?+0 0x2f28480 con 0x2ed68c0
-64> 2012-11-29 00:14:13.873555 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 263
-63> 2012-11-29 00:14:13.873557 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-62> 2012-11-29 00:14:13.873567 7f5bb2889700 1 -
61> 2012-11-29 00:14:13.873580 7f5bb2889700 0 mds.0.cache creating system inode with ino:608 10.1.10.21:6803/7389 --> 10.1.10.21:6804/3310 -- osd_op(mds.0.7:19 608.00000000 [setxattr path (12),setxattr parent (39),tmapup 0~0] 1.c4405e8e) v4 -- ?+0 0x2f28240 con 0x2ebdc80
-60> 2012-11-29 00:14:13.873602 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 263
-59> 2012-11-29 00:14:13.873604 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-58> 2012-11-29 00:14:13.873607 7f5bb2889700 1 -
57> 2012-11-29 00:14:13.873614 7f5bb2889700 0 mds.0.cache creating system inode with ino:609 10.1.10.21:6803/7389 --> 10.1.10.26:6800/15105 -- osd_op(mds.0.7:20 609.00000000 [setxattr path (12),setxattr parent (39),tmapup 0~0] 1.60b82d07) v4 -- ?+0 0x2f28000 con 0x2ed6140
-56> 2012-11-29 00:14:13.873638 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 263
-55> 2012-11-29 00:14:13.873640 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-54> 2012-11-29 00:14:13.873643 7f5bb2889700 1 -
53> 2012-11-29 00:14:13.873649 7f5bb2889700 0 mds.0.cache creating system inode with ino:200 10.1.10.21:6803/7389 --> 10.1.10.26:6800/15105 -- osd_op(mds.0.7:21 100.00000000 [setxattr path (5),setxattr parent (13),tmapput 0~4089] 1.c5265ab3) v4 -- ?+0 0x2f06240 con 0x2ed6140
-52> 2012-11-29 00:14:13.873686 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 4117
-51> 2012-11-29 00:14:13.873688 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-50> 2012-11-29 00:14:13.873691 7f5bb2889700 1 -
49> 2012-11-29 00:14:13.873706 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 399 10.1.10.21:6803/7389 --> 10.1.10.21:6804/3310 -- osd_op(mds.0.7:22 100.00000000.inode [writefull 0~399] 1.85dde07f) v4 -- ?+0 0x2f5ed80 con 0x2ebdc80
-48> 2012-11-29 00:14:13.873708 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-47> 2012-11-29 00:14:13.873713 7f5bb2889700 1 -
46> 2012-11-29 00:14:13.873731 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 29 10.1.10.21:6803/7389 --> 10.1.10.26:6800/15105 -- osd_op(mds.0.7:23 mds0_inotable [writefull 0~29] 1.b852b893) v4 -- ?+0 0x2f5eb40 con 0x2ed6140
-45> 2012-11-29 00:14:13.873732 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-44> 2012-11-29 00:14:13.873735 7f5bb2889700 1 -
43> 2012-11-29 00:14:13.873748 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 17 10.1.10.21:6803/7389 --> 10.1.10.26:6803/15483 -- osd_op(mds.0.7:24 mds0_sessionmap [writefull 0~17] 1.3270c60b) v4 -- ?+0 0x2f5e900 con 0x2ebdb40
-42> 2012-11-29 00:14:13.873751 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-41> 2012-11-29 00:14:13.873754 7f5bb2889700 1 -
40> 2012-11-29 00:14:13.873767 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 29 10.1.10.21:6803/7389 --> 10.1.10.26:6800/15105 -- osd_op(mds.0.7:25 mds_anchortable [writefull 0~29] 1.a977f6a7) v4 -- ?+0 0x2f5e6c0 con 0x2ed6140
-39> 2012-11-29 00:14:13.873768 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-38> 2012-11-29 00:14:13.873771 7f5bb2889700 1 -
37> 2012-11-29 00:14:13.873784 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) take 41 10.1.10.21:6803/7389 --> 10.1.10.22:6800/31304 -- osd_op(mds.0.7:26 mds_snaptable [writefull 0~41] 1.d90270ad) v4 -- ?+0 0x2f5e480 con 0x2ed6b40
-36> 2012-11-29 00:14:13.873786 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) take 1
-35> 2012-11-29 00:14:13.873817 7f5bb2889700 1 -
34> 2012-11-29 00:14:13.873829 7f5bb2889700 1 mds.0.cache handle_mds_failure mds.0 : recovery peers are 10.1.10.21:6803/7389 <== osd.4 10.1.10.22:6800/31304 1 ==== osd_op_reply(26 mds_snaptable [writefull 0~41] ondisk = -6 (No such device or address)) v4 ==== 112+0+0 (4018908758 0 0) 0x2f6a200 con 0x2ed6b40
-33> 2012-11-29 00:14:13.873835 7f5bb2889700 5 mds.0.migrator handle_mds_failure_or_stop mds.0
-32> 2012-11-29 00:14:13.873861 7f5bb2889700 5 mds.0.bal rebalance done
-31> 2012-11-29 00:14:13.873869 7f5bb2889700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) put 535 (0xaab328 -> 0)
-30> 2012-11-29 00:14:13.889027 7f5bb2889700 0 mds.0.7 ms_handle_connect on 10.1.10.21:6804/3310
-29> 2012-11-29 00:14:13.892693 7f5bb2889700 0 mds.0.7 ms_handle_connect on 10.1.10.22:6803/1418
-28> 2012-11-29 00:14:13.893313 7f5bb2889700 0 mds.0.7 ms_handle_connect on 10.1.10.22:6800/31304
-27> 2012-11-29 00:14:13.896744 7f5bb2889700 0 mds.0.7 ms_handle_connect on 10.1.10.26:6800/15105
-26> 2012-11-29 00:14:13.900367 7f5bb007d700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 195 (0 -> 195)
-25> 2012-11-29 00:14:13.900408 7f5baff7c700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 112 (195 -> 307)
-24> 2012-11-29 00:14:13.900443 7f5bb2889700 1 -
-23> 2012-11-29 00:14:13.900469 7f5bb2889700 5 throttle(objecter_bytes 0x2eb7238) put 41 (0xaab328 -> 8569)
-22> 2012-11-29 00:14:13.900472 7f5bb2889700 5 throttle(objecter_ops 0x2eb72b0) put 1 (0xaab328 -> 25)
-21> 2012-11-29 00:14:13.901255 7f5bb2889700 -1 mds/MDSTable.cc: In function 'virtual void C_MT_Save::finish(int)' thread 7f5bb2889700 time 2012-11-29 00:14:13.900486
mds/MDSTable.cc: 39: FAILED assert(r >= 0)
ceph version 0.48.2argonaut (commit:3e02b2fad88c2a95d9c0c86878f10d1beb780bfe)
1: /usr/bin/ceph-mds() [0x668bb2]
2: (Objecter::handle_osd_op_reply(MOSDOpReply*)+0xe03) [0x6b6083]
3: (MDS::handle_core_message(Message*)+0xae8) [0x4c1708]
4: (MDS::_dispatch(Message*)+0x2f) [0x4c18cf]
5: (MDS::ms_dispatch(Message*)+0x1eb) [0x4c34ab]
6: (SimpleMessenger::DispatchQueue::entry()+0x903) [0x7579a3]
7: (SimpleMessenger::dispatch_entry()+0x24) [0x758744]
8: (SimpleMessenger::DispatchThread::entry()+0xd) [0x717a5d]
9: (()+0x7e9a) [0x7f5bb7c68e9a]
10: (clone()+0x6d) [0x7f5bb6b0c4bd]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
20> 2012-11-29 00:14:13.920617 7f5bafe7b700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 111 (307 -> 418)
-19> 2012-11-29 00:14:13.920736 7f5bafe7b700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 111 (418 -> 529)
-18> 2012-11-29 00:14:13.920756 7f5bafe7b700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 112 (529 -> 641)
-17> 2012-11-29 00:14:13.921239 7f5bafe7b700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 114 (641 -> 755)
-16> 2012-11-29 00:14:13.921259 7f5bafe7b700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 193 (755 -> 948)
-15> 2012-11-29 00:14:13.921277 7f5bafe7b700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 195 (948 -> 1143)
-14> 2012-11-29 00:14:13.921294 7f5bafe7b700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 195 (1143 -> 1338)
-13> 2012-11-29 00:14:13.921322 7f5bb017e700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 111 (1338 -> 1449)
-12> 2012-11-29 00:14:13.921364 7f5bb017e700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 193 (1449 -> 1642)
-11> 2012-11-29 00:14:13.921385 7f5bb017e700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 195 (1642 -> 1837)
-10> 2012-11-29 00:14:13.921403 7f5bb017e700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 195 (1837 -> 2032)
-9> 2012-11-29 00:14:13.921425 7f5bb017e700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 195 (2032 -> 2227)
-8> 2012-11-29 00:14:13.924156 7f5bafc79700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 111 (2227 -> 2338)
-7> 2012-11-29 00:14:13.924344 7f5bafc79700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 111 (2338 -> 2449)
-6> 2012-11-29 00:14:13.924412 7f5bafc79700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 115 (2449 -> 2564)
-5> 2012-11-29 00:14:13.924470 7f5bafc79700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 195 (2564 -> 2759)
-4> 2012-11-29 00:14:13.925622 7f5bafd7a700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 195 (2759 -> 2954)
-3> 2012-11-29 00:14:13.925676 7f5bafd7a700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 195 (2954 -> 3149)
-2> 2012-11-29 00:14:13.925722 7f5bafd7a700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 195 (3149 -> 3344)
-1> 2012-11-29 00:14:13.925770 7f5bafd7a700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 111 (3344 -> 3455)
0> 2012-11-29 00:14:13.925813 7f5bafd7a700 5 throttle(msgr_dispatch_throttler-mds 0x2e859e0) get 400 (3455 -> 3855)
-- end dump of recent events ---
2012-11-29 00:14:14.054031 7f5bb2889700 -1 ** Caught signal (Aborted) *
in thread 7f5bb2889700
ceph version 0.48.2argonaut (commit:3e02b2fad88c2a95d9c0c86878f10d1beb780bfe)
1: /usr/bin/ceph-mds() [0x7e315a]
2: (()+0xfcb0) [0x7f5bb7c70cb0]
3: (gsignal()+0x35) [0x7f5bb6a50445]
4: (abort()+0x17b) [0x7f5bb6a53bab]
5: (_gnu_cxx::_verbose_terminate_handler()+0x11d) [0x7f5bb739e69d]
6: (()+0xb5846) [0x7f5bb739c846]
7: (()+0xb5873) [0x7f5bb739c873]
8: (()+0xb596e) [0x7f5bb739c96e]
9: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x1de) [0x7771fe]
10: /usr/bin/ceph-mds() [0x668bb2]
11: (Objecter::handle_osd_op_reply(MOSDOpReply*)+0xe03) [0x6b6083]
12: (MDS::handle_core_message(Message*)+0xae8) [0x4c1708]
13: (MDS::_dispatch(Message*)+0x2f) [0x4c18cf]
14: (MDS::ms_dispatch(Message*)+0x1eb) [0x4c34ab]
15: (SimpleMessenger::DispatchQueue::entry()+0x903) [0x7579a3]
16: (SimpleMessenger::dispatch_entry()+0x24) [0x758744]
17: (SimpleMessenger::DispatchThread::entry()+0xd) [0x717a5d]
18: (()+0x7e9a) [0x7f5bb7c68e9a]
19: (clone()+0x6d) [0x7f5bb6b0c4bd]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
--- begin dump of recent events ---
0> 2012-11-29 00:14:14.054031 7f5bb2889700 -1 ** Caught signal (Aborted) *
in thread 7f5bb2889700
ceph version 0.48.2argonaut (commit:3e02b2fad88c2a95d9c0c86878f10d1beb780bfe)
1: /usr/bin/ceph-mds() [0x7e315a]
2: (()+0xfcb0) [0x7f5bb7c70cb0]
3: (gsignal()+0x35) [0x7f5bb6a50445]
4: (abort()+0x17b) [0x7f5bb6a53bab]
5: (_gnu_cxx::_verbose_terminate_handler()+0x11d) [0x7f5bb739e69d]
6: (()+0xb5846) [0x7f5bb739c846]
7: (()+0xb5873) [0x7f5bb739c873]
8: (()+0xb596e) [0x7f5bb739c96e]
9: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x1de) [0x7771fe]
10: /usr/bin/ceph-mds() [0x668bb2]
11: (Objecter::handle_osd_op_reply(MOSDOpReply*)+0xe03) [0x6b6083]
12: (MDS::handle_core_message(Message*)+0xae8) [0x4c1708]
13: (MDS::_dispatch(Message*)+0x2f) [0x4c18cf]
14: (MDS::ms_dispatch(Message*)+0x1eb) [0x4c34ab]
15: (SimpleMessenger::DispatchQueue::entry()+0x903) [0x7579a3]
16: (SimpleMessenger::dispatch_entry()+0x24) [0x758744]
17: (SimpleMessenger::DispatchThread::entry()+0xd) [0x717a5d]
18: (()+0x7e9a) [0x7f5bb7c68e9a]
19: (clone()+0x6d) [0x7f5bb6b0c4bd]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
--- end dump of recent events ---
e128: 1/1/1 up {0=a=up:creating}
root@ceph1:/var/lib/ceph/mds/ceph-a#
Files
Updated by Anonymous over 11 years ago
ubuntu@ceph1:/var/log/ceph$ uname -a
Linux ceph1 3.2.0-23-virtual #36-Ubuntu SMP Tue Apr 10 22:29:03 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux
DISTRIB_DESCRIPTION="Ubuntu 12.04 LTS"
Updated by Sage Weil over 11 years ago
- Status changed from New to Need More Info
- Priority changed from Normal to High
ENXIO from teh OSD means we sent the request to the wrong osd. what version is the osd running?
also, do you have the osd logs? there should be a message like 'misdirected op ...' in there somewhere...
Updated by Anonymous over 11 years ago
ubuntu@ceph1:/var/log/ceph$ sudo service ceph status
=== mon.a ===
mon.a: running 0.48.2argonaut
=== mds.a ===
mds.a: not running.
=== osd.0 ===
osd.0: running 0.48.2argonaut
=== osd.1 ===
osd.1: running 0.48.2argonaut
attached tarfile of logs.
Updated by Anonymous over 11 years ago
- File ceph-osd.tar.gz ceph-osd.tar.gz added
too large of a file. Only did a tar for the osd logs.
Updated by Anonymous over 11 years ago
I added requested info last week on 11/29. How do I change Status?
Updated by Anonymous over 11 years ago
How was this bug verified? Would you provide the test and its description in this bug, please.
Updated by Dan Mick over 11 years ago
Verified just means we agree it's a bug. New->Verified->In Progress->Need Review->Testing->Resolved is the simple path through states
Updated by Ian Colle over 11 years ago
- Project changed from Ceph to CephFS
- Category changed from 1 to 47
Updated by Greg Farnum over 11 years ago
- Project changed from CephFS to Ceph
- Category changed from 47 to 1
Given what we know so far (the Op got sent to the wrong OSD) this is a bug in the Objecter, not the MDS. Or possibly the actual OSDs, but nothing to do with the MDS proper.
Updated by Sage Weil over 11 years ago
- Status changed from 12 to Won't Fix
if/when see this on bobtail or later, we'll investigate.
Updated by John Spray over 7 years ago
- Project changed from Ceph to CephFS
- Category deleted (
1)
Bulk updating project=ceph category=mds bugs so that I can remove the MDS category from the Ceph project to avoid confusion.