Hi,
snip
2012-05-22 12:02:02.678094 7f5f43b5d780 1 -- 0.0.0.0:6800/23071 messenger.start
2012-05-22 12:02:02.678245 7f5f43b5d780 1 -- 0.0.0.0:6800/23071 accepter.start
2012-05-22 12:02:02.679672 7f5f43b5d780 1 -- 0.0.0.0:6800/23071 -->
10.3.0.12:6789/0 -- auth(proto 0 26 bytes epoch 0) v1 -- ?+0 0x13ea400
con 0x13ecdc0
2012-05-22 12:02:02.680105 7f5f43b5c700 1 -- 10.3.0.12:6800/23071
learned my addr 10.3.0.12:6800/23071
2012-05-22 12:02:02.680390 7f5f3ecd1700 0 mds.-1.0 ms_handle_connect
on 10.3.0.12:6789/0
2012-05-22 12:02:02.681402 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 1 ==== mon_map v1 ==== 469+0+0 (56645397 0 0)
0x13eaa00 con 0x13ecdc0
2012-05-22 12:02:02.681529 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 2 ==== auth_reply(proto 1 0 Success) v1 ====
24+0+0 (3086217166 0 0) 0x13ea800 con 0x13ecdc0
2012-05-22 12:02:02.681596 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 -- mon_subscribe({monmap=0+}) v2 -- ?+0 0x1404380 con
0x13ecdc0
2012-05-22 12:02:02.681932 7f5f43b5d780 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 -- mdsbeacon(6308/c up:boot seq 1 v0) v2 -- ?+0
0x13f7c80 con 0x13ecdc0
2012-05-22 12:02:02.682060 7f5f43b5d780 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 -- mon_subscribe({monmap=2+,osdmap=0}) v2 -- ?+0
0x14041c0 con 0x13ecdc0
2012-05-22 12:02:02.682109 7f5f43b5d780 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 -- mon_subscribe({mdsmap=0+,monmap=2+,osdmap=0}) v2
-- ?+0 0x14048c0 con 0x13ecdc0
2012-05-22 12:02:02.682421 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 3 ==== mon_map v1 ==== 469+0+0 (56645397 0 0)
0x1407600 con 0x13ecdc0
2012-05-22 12:02:02.682554 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 4 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0
(311377444 0 0) 0x1404380 con 0x13ecdc0
2012-05-22 12:02:02.682978 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 5 ==== osd_map(234..234 src has 1..234) v3 ====
19741+0+0 (3560848488 0 0) 0x1407400 con 0x13ecdc0
2012-05-22 12:02:02.683587 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 6 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0
(311377444 0 0) 0x1404a80 con 0x13ecdc0
2012-05-22 12:02:02.683601 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 7 ==== mdsmap(e 52010) v1 ==== 535+0+0
(2872786254 0 0) 0x1407200 con 0x13ecdc0
2012-05-22 12:02:02.683631 7f5f3ecd1700 5 mds.-1.0 handle_mds_map
epoch 52010 from mon.2
2012-05-22 12:02:02.683818 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 8 ==== osd_map(234..234 src has 1..234) v3 ====
19741+0+0 (3560848488 0 0) 0x1407000 con 0x13ecdc0
2012-05-22 12:02:02.683932 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 9 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0
(311377444 0 0) 0x14041c0 con 0x13ecdc0
2012-05-22 12:02:02.768244 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 10 ==== mdsmap(e 52011) v1 ==== 733+0+0
(1289862739 0 0) 0x1407a00 con 0x13ecdc0
2012-05-22 12:02:02.768364 7f5f3ecd1700 5 mds.-1.-1 handle_mds_map
epoch 52011 from mon.2
2012-05-22 12:02:02.768413 7f5f3ecd1700 1 mds.-1.0 handle_mds_map standby
2012-05-22 12:02:02.933902 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 11 ==== mdsmap(e 52012) v1 ==== 535+0+0
(3794450792 0 0) 0x1407800 con 0x13ecdc0
2012-05-22 12:02:02.933965 7f5f3ecd1700 5 mds.-1.0 handle_mds_map
epoch 52012 from mon.2
2012-05-22 12:02:02.934007 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071
mark_down 10.3.0.12:6800/23046 -- pipe dne
2012-05-22 12:02:02.934016 7f5f3ecd1700 1 mds.0.49 handle_mds_map i
am now mds.0.49
2012-05-22 12:02:02.934030 7f5f3ecd1700 1 mds.0.49 handle_mds_map
state change up:standby --> up:replay
2012-05-22 12:02:02.934040 7f5f3ecd1700 1 mds.0.49 replay_start
2012-05-22 12:02:02.934052 7f5f3ecd1700 1 mds.0.49 recovery set is
2012-05-22 12:02:02.934055 7f5f3ecd1700 1 mds.0.49 need osdmap epoch
235, have 234
2012-05-22 12:02:02.934058 7f5f3ecd1700 1 mds.0.49 waiting for
osdmap 235 (which blacklists prior instance)
2012-05-22 12:02:02.934076 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 --
mon_subscribe({mdsmap=52013+,monmap=2+,osdmap=235}) v2 -- ?+0
0x14041c0 con 0x13ecdc0
2012-05-22 12:02:02.934154 7f5f3ecd1700 1 mds.0.cache
handle_mds_failure mds.0 : recovery peers are
2012-05-22 12:02:02.934184 7f5f3ecd1700 5 mds.0.migrator
handle_mds_failure_or_stop mds.0
2012-05-22 12:02:02.992970 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 12 ==== osd_map(235..235 src has 1..235) v3
==== 300+0+0 (2376656173 0 0) 0x1407600 con 0x13ecdc0
2012-05-22 12:02:02.993145 7f5f3ecd1700 2 mds.0.49 boot_start 1:
opening inotable
2012-05-22 12:02:02.993411 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:1 mds0_inotable [read 0~0]
1.b852b893) v4 -- ?+0 0x13e36c0 con 0x1408a00
2012-05-22 12:02:02.993471 7f5f3ecd1700 2 mds.0.49 boot_start 1:
opening sessionmap
2012-05-22 12:02:02.993553 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:2 mds0_sessionmap [read 0~0]
1.3270c60b) v4 -- ?+0 0x13e3d80 con 0x1408a00
2012-05-22 12:02:02.993577 7f5f3ecd1700 2 mds.0.49 boot_start 1:
opening anchor table
2012-05-22 12:02:02.993625 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:3 mds_anchortable [read 0~0]
1.a977f6a7) v4 -- ?+0 0x13e3900 con 0x1408a00
2012-05-22 12:02:02.993634 7f5f3ecd1700 2 mds.0.49 boot_start 1:
opening snap table
2012-05-22 12:02:02.993671 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:4 mds_snaptable [read 0~0]
1.d90270ad) v4 -- ?+0 0x140d6c0 con 0x1408a00
2012-05-22 12:02:02.993680 7f5f3ecd1700 2 mds.0.49 boot_start 1:
opening mds log
2012-05-22 12:02:02.993700 7f5f3ecd1700 5 mds.0.log open discovering log bounds
2012-05-22 12:02:02.993792 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:5 200.00000000 [read 0~0]
1.844f3494) v4 -- ?+0 0x140d480 con 0x1408a00
2012-05-22 12:02:02.993826 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 13 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0
(311377444 0 0) 0x140b380 con 0x13ecdc0
2012-05-22 12:02:02.994043 7f5f3ecd1700 0 mds.0.49 ms_handle_connect
on 10.3.0.12:6801/1172
2012-05-22 12:02:02.995288 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 1 ==== osd_op_reply(1 mds0_inotable [read
0~29] = 0) v4 ==== 112+0+29 (3509020669 0 2080707671) 0x1407400 con
0x1408a00
2012-05-22 12:02:02.995518 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 2 ==== osd_op_reply(2 mds0_sessionmap [read
0~10591] = 0) v4 ==== 114+0+10591 (734241002 0 1640895633) 0x1407000
con 0x1408a00
2012-05-22 12:02:02.995836 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 3 ==== osd_op_reply(3 mds_anchortable [read
0~29] = 0) v4 ==== 114+0+29 (1868654419 0 218791405) 0x1407200 con
0x1408a00
2012-05-22 12:02:02.995890 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 4 ==== osd_op_reply(4 mds_snaptable [read
0~41] = 0) v4 ==== 112+0+41 (3594810684 0 2312406677) 0x1407e00 con
0x1408a00
2012-05-22 12:02:02.995940 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 5 ==== osd_op_reply(5 200.00000000 [read
0~84] = 0) v4 ==== 111+0+84 (3837001893 0 1130699602) 0x1407c00 con
0x1408a00
2012-05-22 12:02:02.996032 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:6 200.0000016d [stat 0~0]
1.6f7c9ad6 rwordered) v4 -- ?+0 0x140d480 con 0x1408a00
2012-05-22 12:02:02.996107 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:7 200.0000016e [stat 0~0]
1.9feb60a6 rwordered) v4 -- ?+0 0x140d6c0 con 0x1408a00
2012-05-22 12:02:02.996608 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 6 ==== osd_op_reply(6 200.0000016d [stat
0~0] = 0) v4 ==== 111+0+16 (1485433033 0 624451111) 0x1407a00 con
0x1408a00
2012-05-22 12:02:02.997170 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 7 ==== osd_op_reply(7 200.0000016e [stat
0~0] = 0) v4 ==== 111+0+16 (2013887546 0 3894377183) 0x1407000 con
0x1408a00
2012-05-22 12:02:02.997202 7f5f3ecd1700 2 mds.0.49 boot_start 2:
loading/discovering base inodes
2012-05-22 12:02:02.997211 7f5f3ecd1700 0 mds.0.cache creating system
inode with ino:100
2012-05-22 12:02:02.999723 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:8 100.00000000 [getxattr inode]
1.c5265ab3) v4 -- ?+0 0x13e36c0 con 0x1408a00
2012-05-22 12:02:02.999788 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:9 100.00000000.inode [read 0~0]
1.85dde07f) v4 -- ?+0 0x13e3900 con 0x1408a00
2012-05-22 12:02:02.999804 7f5f3ecd1700 0 mds.0.cache creating system
inode with ino:1
2012-05-22 12:02:02.999874 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:10 1.00000000 [getxattr inode]
1.6b2cdaff) v4 -- ?+0 0x140db40 con 0x1408a00
2012-05-22 12:02:03.000142 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:11 1.00000000.inode [read 0~0]
1.232c0e14) v4 -- ?+0 0x140d900 con 0x1408a00
2012-05-22 12:02:03.000936 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 8 ==== osd_op_reply(9 100.00000000.inode
[read 0~399] = 0) v4 ==== 117+0+399 (2159939521 0 4121830280)
0x1407400 con 0x1408a00
2012-05-22 12:02:03.001468 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 9 ==== osd_op_reply(8 100.00000000
[getxattr] = -61 (No data available)) v4 ==== 111+0+0 (4127029859 0 0)
0x1407600 con 0x1408a00
2012-05-22 12:02:03.001669 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 10 ==== osd_op_reply(10 1.00000000
[getxattr] = -61 (No data available)) v4 ==== 109+0+0 (1727840390 0 0)
0x1407800 con 0x1408a00
2012-05-22 12:02:03.001742 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 11 ==== osd_op_reply(11 1.00000000.inode
[read 0~428] = 0) v4 ==== 115+0+428 (3364705558 0 715602140) 0x1407200
con 0x1408a00
2012-05-22 12:02:03.001809 7f5f3ecd1700 2 mds.0.49 boot_start 3:
replaying mds log
2012-05-22 12:02:03.002198 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:12 200.0000014f [read
2535~4191769] 1.b79a8c0b) v4 -- ?+0 0x140d480 con 0x1408a00
2012-05-22 12:02:03.002290 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:13 200.00000150 [read
0~4194304] 1.23163b1d) v4 -- ?+0 0x13e36c0 con 0x1408a00
2012-05-22 12:02:03.004043 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:14 200.00000151 [read
0~4194304] 1.28b76431) v4 -- ?+0 0x140d6c0 con 0x1408a00
2012-05-22 12:02:03.004205 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:15 200.00000152 [read
0~4194304] 1.ae9bb683) v4 -- ?+0 0x140d480 con 0x1408a00
2012-05-22 12:02:03.004380 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:16 200.00000153 [read
0~4194304] 1.d9966785) v4 -- ?+0 0x140d900 con 0x1408a00
2012-05-22 12:02:03.004454 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:17 200.00000154 [read
0~4194304] 1.47f9bf13) v4 -- ?+0 0x140db40 con 0x1408a00
2012-05-22 12:02:03.004520 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:18 200.00000155 [read
0~4194304] 1.460264c4) v4 -- ?+0 0x13e3900 con 0x1408a00
2012-05-22 12:02:03.004582 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:19 200.00000156 [read
0~4194304] 1.cae377ec) v4 -- ?+0 0x13e36c0 con 0x1408a00
2012-05-22 12:02:03.004650 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:20 200.00000157 [read
0~4194304] 1.1c534f6b) v4 -- ?+0 0x140d6c0 con 0x1408a00
2012-05-22 12:02:03.004740 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:21 200.00000158 [read
0~4194304] 1.21f6fd52) v4 -- ?+0 0x143f900 con 0x1408a00
2012-05-22 12:02:03.031626 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 12 ==== osd_op_reply(12 200.0000014f [read
2535~4191769] = 0) v4 ==== 111+0+4191769 (86938826 0 940254350)
0x1407600 con 0x1408a00
2012-05-22 12:02:03.049765 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 13 ==== osd_op_reply(13 200.00000150 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (2540809359 0 2765354474)
0x1407400 con 0x1408a00
2012-05-22 12:02:03.061435 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 14 ==== osd_op_reply(14 200.00000151 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (2370055404 0 728673944)
0x1407000 con 0x1408a00
2012-05-22 12:02:03.073952 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 15 ==== osd_op_reply(15 200.00000152 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (2835608127 0 4176800115)
0x1407a00 con 0x1408a00
2012-05-22 12:02:03.086138 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:22 200.00000159 [read
0~4194304] 1.11c4d2c4) v4 -- ?+0 0x143f480 con 0x1408a00
2012-05-22 12:02:03.087461 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 16 ==== osd_op_reply(16 200.00000153 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (414535972 0 2827888072)
0x1407c00 con 0x1408a00
2012-05-22 12:02:03.119482 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 17 ==== osd_op_reply(17 200.00000154 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (2490448686 0 1942553121)
0x1407e00 con 0x1408a00
2012-05-22 12:02:03.119562 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 18 ==== osd_op_reply(18 200.00000155 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (1664826329 0 2280396596)
0x143ee00 con 0x1408a00
2012-05-22 12:02:03.131469 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 19 ==== osd_op_reply(19 200.00000156 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (324288200 0 2843054375)
0x143ec00 con 0x1408a00
2012-05-22 12:02:03.139410 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:23 200.0000015a [read
0~4194304] 1.d46a5844) v4 -- ?+0 0x143f000 con 0x1408a00
2012-05-22 12:02:03.145585 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 20 ==== osd_op_reply(20 200.00000157 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (542705527 0 967023793)
0x143ea00 con 0x1408a00
2012-05-22 12:02:03.156508 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 21 ==== osd_op_reply(21 200.00000158 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (3296968726 0 3798599763)
0x143e800 con 0x1408a00
2012-05-22 12:02:03.172296 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 22 ==== osd_op_reply(22 200.00000159 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (2210915791 0 2737758750)
0x143e600 con 0x1408a00
2012-05-22 12:02:03.182754 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:24 200.0000015b [read
0~4194304] 1.a8a12f71) v4 -- ?+0 0x140d480 con 0x1408a00
2012-05-22 12:02:03.185018 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 23 ==== osd_op_reply(23 200.0000015a [read
0~4194304] = 0) v4 ==== 111+0+4194304 (859847618 0 611094159)
0x143e400 con 0x1408a00
2012-05-22 12:02:03.205868 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 24 ==== osd_op_reply(24 200.0000015b [read
0~4194304] = 0) v4 ==== 111+0+4194304 (541055975 0 524786588)
0x143e200 con 0x1408a00
2012-05-22 12:02:03.225090 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:25 200.0000015c [read
0~4194304] 1.941114d8) v4 -- ?+0 0x13e3900 con 0x1408a00
2012-05-22 12:02:03.242516 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 25 ==== osd_op_reply(25 200.0000015c [read
0~4194304] = 0) v4 ==== 111+0+4194304 (1141303529 0 1957418634)
0x143e200 con 0x1408a00
2012-05-22 12:02:03.263094 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:26 200.0000015d [read
0~4194304] 1.bdfe9959) v4 -- ?+0 0x143fb40 con 0x1408a00
2012-05-22 12:02:03.278274 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 26 ==== osd_op_reply(26 200.0000015d [read
0~4194304] = 0) v4 ==== 111+0+4194304 (3503869406 0 773787611)
0x143e400 con 0x1408a00
2012-05-22 12:02:03.300327 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:27 200.0000015e [read
0~4194304] 1.b8cf7266) v4 -- ?+0 0x140db40 con 0x1408a00
2012-05-22 12:02:03.316669 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 27 ==== osd_op_reply(27 200.0000015e [read
0~4194304] = 0) v4 ==== 111+0+4194304 (1073368869 0 2950585796)
0x143e600 con 0x1408a00
2012-05-22 12:02:03.336096 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:28 200.0000015f [read
0~4194304] 1.2980b721) v4 -- ?+0 0x1ba9b40 con 0x1408a00
2012-05-22 12:02:03.352131 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 28 ==== osd_op_reply(28 200.0000015f [read
0~4194304] = 0) v4 ==== 111+0+4194304 (3513547997 0 1851987047)
0x143e800 con 0x1408a00
2012-05-22 12:02:03.371923 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:29 200.00000160 [read
0~4194304] 1.574ae4ae) v4 -- ?+0 0x1ba96c0 con 0x1408a00
2012-05-22 12:02:03.388290 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 29 ==== osd_op_reply(29 200.00000160 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (2670366445 0 4080047592)
0x143ea00 con 0x1408a00
2012-05-22 12:02:03.410233 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:30 200.00000161 [read
0~4194304] 1.87287887) v4 -- ?+0 0x1ba9240 con 0x1408a00
2012-05-22 12:02:03.426379 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 30 ==== osd_op_reply(30 200.00000161 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (2306991298 0 2632960265)
0x143ec00 con 0x1408a00
2012-05-22 12:02:03.450460 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:31 200.00000162 [read
0~4194304] 1.f23e2d31) v4 -- ?+0 0x140db40 con 0x1408a00
2012-05-22 12:02:03.466463 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 31 ==== osd_op_reply(31 200.00000162 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (4169482190 0 1357295963)
0x143ee00 con 0x1408a00
2012-05-22 12:02:03.492735 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:32 200.00000163 [read
0~4194304] 1.ac437fe4) v4 -- ?+0 0x143fb40 con 0x1408a00
2012-05-22 12:02:03.528942 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:33 200.00000164 [read
0~4194304] 1.5a233b33) v4 -- ?+0 0x143f480 con 0x1408a00
2012-05-22 12:02:03.570058 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:34 200.00000165 [read
0~4194304] 1.1f8332c7) v4 -- ?+0 0x13e3900 con 0x1408a00
2012-05-22 12:02:03.570757 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 32 ==== osd_op_reply(32 200.00000163 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (2725338461 0 3594916529)
0x1d3ce00 con 0x1408a00
2012-05-22 12:02:03.589941 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 33 ==== osd_op_reply(33 200.00000164 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (988396741 0 694923933)
0x1d3cc00 con 0x1408a00
2012-05-22 12:02:03.594028 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 34 ==== osd_op_reply(34 200.00000165 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (894342962 0 1116835292)
0x1d3ca00 con 0x1408a00
2012-05-22 12:02:03.616937 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:35 200.00000166 [read
0~4194304] 1.8ce28c4a) v4 -- ?+0 0x1d43b40 con 0x1408a00
2012-05-22 12:02:03.633104 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 35 ==== osd_op_reply(35 200.00000166 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (34046407 0 554791290) 0x1d3c800
con 0x1408a00
2012-05-22 12:02:03.656933 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:36 200.00000167 [read
0~4194304] 1.7e245b6f) v4 -- ?+0 0x1d436c0 con 0x1408a00
2012-05-22 12:02:03.672729 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 36 ==== osd_op_reply(36 200.00000167 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (3542980681 0 3731006206)
0x1d3c600 con 0x1408a00
2012-05-22 12:02:03.694800 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:37 200.00000168 [read
0~4194304] 1.b1365376) v4 -- ?+0 0x1d43240 con 0x1408a00
2012-05-22 12:02:03.713056 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 37 ==== osd_op_reply(37 200.00000168 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (3143521032 0 2534577188)
0x1d3c400 con 0x1408a00
2012-05-22 12:02:03.732734 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:38 200.00000169 [read
0~4194304] 1.ff0405d0) v4 -- ?+0 0x1d43b40 con 0x1408a00
2012-05-22 12:02:03.751450 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 38 ==== osd_op_reply(38 200.00000169 [read
0~4194304] = 0) v4 ==== 111+0+4194304 (733149638 0 738384784)
0x1d3c200 con 0x1408a00
2012-05-22 12:02:03.770040 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:39 200.0000016a [read
0~4194304] 1.3f32f1a0) v4 -- ?+0 0x143f480 con 0x1408a00
2012-05-22 12:02:03.787041 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 39 ==== osd_op_reply(39 200.0000016a [read
0~4194304] = 0) v4 ==== 111+0+4194304 (79880031 0 463711875) 0x1d3c000
con 0x1408a00
2012-05-22 12:02:03.807842 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:40 200.0000016b [read
0~4194304] 1.c299cbd3) v4 -- ?+0 0x140db40 con 0x1408a00
2012-05-22 12:02:03.824629 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 40 ==== osd_op_reply(40 200.0000016b [read
0~4194304] = 0) v4 ==== 111+0+4194304 (707054799 0 1356117031)
0x1d3cc00 con 0x1408a00
2012-05-22 12:02:03.845870 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:41 200.0000016c [read
0~4194304] 1.41d6438b) v4 -- ?+0 0x1ba96c0 con 0x1408a00
2012-05-22 12:02:03.862209 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 41 ==== osd_op_reply(41 200.0000016c [read
0~4194304] = 0) v4 ==== 111+0+4194304 (78005920 0 1848623926)
0x1d3ce00 con 0x1408a00
2012-05-22 12:02:03.882715 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:42 200.0000016d [read
0~4194304] 1.6f7c9ad6) v4 -- ?+0 0x1d58d80 con 0x1408a00
2012-05-22 12:02:03.901124 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 42 ==== osd_op_reply(42 200.0000016d [read
0~4194304] = 0) v4 ==== 111+0+4194304 (3681601409 0 3284364392)
0x143ee00 con 0x1408a00
2012-05-22 12:02:03.921699 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:43 200.0000016e [read 0~149004]
1.9feb60a6) v4 -- ?+0 0x1d58900 con 0x1408a00
2012-05-22 12:02:03.923308 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 43 ==== osd_op_reply(43 200.0000016e [read
0~149004] = 0) v4 ==== 111+0+149004 (188018409 0 1584225691) 0x143ec00
con 0x1408a00
2012-05-22 12:02:04.270213 7f5f3c9ca700 1 mds.0.49 replay_done
2012-05-22 12:02:04.270248 7f5f3c9ca700 1 mds.0.49 making mds journal writeable
2012-05-22 12:02:04.270338 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:44 200.0000016e [zero
149004~4045300] 1.9feb60a6) v4 -- ?+0 0x1ea56c0 con 0x1408a00
2012-05-22 12:02:04.270415 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:45 200.0000016f [delete]
1.e6816672) v4 -- ?+0 0x1ea5480 con 0x1408a00
2012-05-22 12:02:04.270488 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:46 200.00000170 [delete]
1.3e8426cd) v4 -- ?+0 0x1ea5240 con 0x1408a00
2012-05-22 12:02:04.270569 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:47 200.00000171 [delete]
1.75986202) v4 -- ?+0 0x1ea5000 con 0x1408a00
2012-05-22 12:02:04.270641 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:48 200.00000172 [delete]
1.d3c077fe) v4 -- ?+0 0x1ea56c0 con 0x1408a00
2012-05-22 12:02:04.270796 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6801/1172 -- osd_op(mds.0.49:49 200.00000173 [delete]
1.3b1f2284) v4 -- ?+0 0x1d58900 con 0x1408a00
2012-05-22 12:02:04.270893 7f5f3c9ca700 2 mds.0.49 i am alone, moving
to state reconnect
2012-05-22 12:02:04.270899 7f5f3c9ca700 3 mds.0.49 request_state up:reconnect
2012-05-22 12:02:04.270916 7f5f3c9ca700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 -- mdsbeacon(6308/c up:reconnect seq 2 v52012) v2 --
?+0 0x140c280 con 0x13ecdc0
2012-05-22 12:02:04.271925 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 44 ==== osd_op_reply(45 200.0000016f
[delete] ondisk = -2 (No such file or directory)) v4 ==== 111+0+0
(3525298709 0 0) 0x143ea00 con 0x1408a00
2012-05-22 12:02:04.272089 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 45 ==== osd_op_reply(46 200.00000170
[delete] ondisk = -2 (No such file or directory)) v4 ==== 111+0+0
(1763128336 0 0) 0x143e800 con 0x1408a00
2012-05-22 12:02:04.272129 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 46 ==== osd_op_reply(47 200.00000171
[delete] ondisk = -2 (No such file or directory)) v4 ==== 111+0+0
(1713780953 0 0) 0x143e600 con 0x1408a00
2012-05-22 12:02:04.272151 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 47 ==== osd_op_reply(48 200.00000172
[delete] ondisk = -2 (No such file or directory)) v4 ==== 111+0+0
(1956823652 0 0) 0x143e400 con 0x1408a00
2012-05-22 12:02:04.272206 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 48 ==== osd_op_reply(49 200.00000173
[delete] ondisk = -2 (No such file or directory)) v4 ==== 111+0+0
(1397982303 0 0) 0x143e200 con 0x1408a00
2012-05-22 12:02:04.274577 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
osd.2 10.3.0.12:6801/1172 49 ==== osd_op_reply(44 200.0000016e
[truncate 149004] ondisk = 0) v4 ==== 111+0+0 (623816276 0 0)
0x143ec00 con 0x1408a00
2012-05-22 12:02:04.358132 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 14 ==== mdsmap(e 52013) v1 ==== 535+0+0
(132891602 0 0) 0x13eae00 con 0x13ecdc0
2012-05-22 12:02:04.358253 7f5f3ecd1700 5 mds.0.49 handle_mds_map
epoch 52013 from mon.2
2012-05-22 12:02:04.358293 7f5f3ecd1700 1 mds.0.49 handle_mds_map i
am now mds.0.49
2012-05-22 12:02:04.358299 7f5f3ecd1700 1 mds.0.49 handle_mds_map
state change up:replay --> up:reconnect
2012-05-22 12:02:04.358314 7f5f3ecd1700 1 mds.0.49 reconnect_start
2012-05-22 12:02:04.358319 7f5f3ecd1700 1 mds.0.49 reopen_log
2012-05-22 12:02:04.358340 7f5f3ecd1700 1 mds.0.server
reconnect_clients -- 2 sessions
2012-05-22 12:02:04.358474 7f5f3ecd1700 5 mds.0.bal rebalance done
2012-05-22 12:02:08.271081 7f5f3d3cd700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 -- mdsbeacon(6308/c up:reconnect seq 3 v52013) v2 --
?+0 0x13f7c80 con 0x13ecdc0
2012-05-22 12:02:08.272677 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 15 ==== mdsbeacon(6308/c up:reconnect seq 3
v52013) v2 ==== 103+0+0 (3383220134 0 0) 0x140c280 con 0x13ecdc0
2012-05-22 12:02:12.271359 7f5f3d3cd700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 -- mdsbeacon(6308/c up:reconnect seq 4 v52013) v2 --
?+0 0x140c780 con 0x13ecdc0
2012-05-22 12:02:12.272900 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 16 ==== mdsbeacon(6308/c up:reconnect seq 4
v52013) v2 ==== 103+0+0 (2744505186 0 0) 0x140cc80 con 0x13ecdc0
2012-05-22 12:02:16.271690 7f5f3d3cd700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 -- mdsbeacon(6308/c up:reconnect seq 5 v52013) v2 --
?+0 0x140c500 con 0x13ecdc0
2012-05-22 12:02:16.273021 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 17 ==== mdsbeacon(6308/c up:reconnect seq 5
v52013) v2 ==== 103+0+0 (3669798405 0 0) 0x140ca00 con 0x13ecdc0
2012-05-22 12:02:20.272061 7f5f3d3cd700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 -- mdsbeacon(6308/c up:reconnect seq 6 v52013) v2 --
?+0 0x140cc80 con 0x13ecdc0
2012-05-22 12:02:20.273524 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 18 ==== mdsbeacon(6308/c up:reconnect seq 6
v52013) v2 ==== 103+0+0 (1372006828 0 0) 0x140c500 con 0x13ecdc0
2012-05-22 12:02:24.272320 7f5f3d3cd700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 -- mdsbeacon(6308/c up:reconnect seq 7 v52013) v2 --
?+0 0x140c280 con 0x13ecdc0
2012-05-22 12:02:24.273966 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 19 ==== mdsbeacon(6308/c up:reconnect seq 7
v52013) v2 ==== 103+0+0 (686707915 0 0) 0x140c780 con 0x13ecdc0
2012-05-22 12:02:28.272580 7f5f3d3cd700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 -- mdsbeacon(6308/c up:reconnect seq 8 v52013) v2 --
?+0 0x13f7c80 con 0x13ecdc0
2012-05-22 12:02:28.273963 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 20 ==== mdsbeacon(6308/c up:reconnect seq 8
v52013) v2 ==== 103+0+0 (2242060324 0 0) 0x140ca00 con 0x13ecdc0
2012-05-22 12:02:32.272813 7f5f3d3cd700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 -- mdsbeacon(6308/c up:reconnect seq 9 v52013) v2 --
?+0 0x1d9c780 con 0x13ecdc0
2012-05-22 12:02:32.274428 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 21 ==== mdsbeacon(6308/c up:reconnect seq 9
v52013) v2 ==== 103+0+0 (4236926275 0 0) 0x1d9c780 con 0x13ecdc0
2012-05-22 12:02:36.273024 7f5f3d3cd700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 -- mdsbeacon(6308/c up:reconnect seq 10 v52013) v2 --
?+0 0x1d9c500 con 0x13ecdc0
2012-05-22 12:02:36.274520 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 22 ==== mdsbeacon(6308/c up:reconnect seq 10
v52013) v2 ==== 103+0+0 (2012338922 0 0) 0x13f7c80 con 0x13ecdc0
2012-05-22 12:02:40.273243 7f5f3d3cd700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 -- mdsbeacon(6308/c up:reconnect seq 11 v52013) v2 --
?+0 0x1d9c280 con 0x13ecdc0
2012-05-22 12:02:40.274602 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 23 ==== mdsbeacon(6308/c up:reconnect seq 11
v52013) v2 ==== 103+0+0 (249079693 0 0) 0x140c280 con 0x13ecdc0
2012-05-22 12:02:44.273455 7f5f3d3cd700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 -- mdsbeacon(6308/c up:reconnect seq 12 v52013) v2 --
?+0 0x1d9c000 con 0x13ecdc0
2012-05-22 12:02:44.274917 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 24 ==== mdsbeacon(6308/c up:reconnect seq 12
v52013) v2 ==== 103+0+0 (1693098825 0 0) 0x140cc80 con 0x13ecdc0
2012-05-22 12:02:48.273651 7f5f3d3cd700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 -- mdsbeacon(6308/c up:reconnect seq 13 v52013) v2 --
?+0 0x1d9ca00 con 0x13ecdc0
2012-05-22 12:02:48.275240 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 25 ==== mdsbeacon(6308/c up:reconnect seq 13
v52013) v2 ==== 103+0+0 (499375662 0 0) 0x1d9cc80 con 0x13ecdc0
2012-05-22 12:02:52.273831 7f5f3d3cd700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 -- mdsbeacon(6308/c up:reconnect seq 14 v52013) v2 --
?+0 0x1d9c780 con 0x13ecdc0
2012-05-22 12:02:52.275198 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 26 ==== mdsbeacon(6308/c up:reconnect seq 14
v52013) v2 ==== 103+0+0 (2528663943 0 0) 0x1d9c780 con 0x13ecdc0
2012-05-22 12:02:52.683463 7f5f3d3cd700 1 mds.0.server reconnect gave
up on client.4114 10.3.0.11:0/32195
2012-05-22 12:02:52.683505 7f5f3d3cd700 1 mds.0.server reconnect gave
up on client.5099 10.3.0.12:0/773
2012-05-22 12:02:52.683527 7f5f3d3cd700 1 mds.0.49 reconnect_done
2012-05-22 12:02:52.683541 7f5f3d3cd700 3 mds.0.49 request_state up:rejoin
2012-05-22 12:02:52.683570 7f5f3d3cd700 1 -- 10.3.0.12:6800/23071 -->
10.3.0.12:6789/0 -- mdsbeacon(6308/c up:rejoin seq 15 v52013) v2 --
?+0 0x140ca00 con 0x13ecdc0
2012-05-22 12:02:53.138079 7f5f3ecd1700 1 -- 10.3.0.12:6800/23071 <==
mon.2 10.3.0.12:6789/0 27 ==== mdsmap(e 52014) v1 ==== 535+0+0
(780151091 0 0) 0x13ea800 con 0x13ecdc0
2012-05-22 12:02:53.138146 7f5f3ecd1700 5 mds.0.49 handle_mds_map
epoch 52014 from mon.2
2012-05-22 12:02:53.138192 7f5f3ecd1700 1 mds.0.49 handle_mds_map i
am now mds.0.49
2012-05-22 12:02:53.138198 7f5f3ecd1700 1 mds.0.49 handle_mds_map
state change up:reconnect --> up:rejoin
2012-05-22 12:02:53.138204 7f5f3ecd1700 1 mds.0.49 rejoin_joint_start
2012-05-22 12:02:53.140710 7f5f3ecd1700 -1 *** Caught signal
(Segmentation fault) **
in thread 7f5f3ecd1700
ceph version 0.46 (commit:cb7f1c9c7520848b0899b26440ac34a8acea58d1)
1: ceph-mds() [0x814279]
2: (()+0xeff0) [0x7f5f4373fff0]
3: (SnapRealm::have_past_parents_open(snapid_t, snapid_t)+0x4f) [0x6cb5ef]
4: (MDCache::check_realm_past_parents(SnapRealm*)+0x2b) [0x55d58b]
5: (MDCache::choose_lock_states_and_reconnect_caps()+0x29c) [0x572eec]
6: (MDCache::rejoin_gather_finish()+0x90) [0x5931a0]
7: (MDCache::rejoin_send_rejoins()+0x2c05) [0x59b9d5]
8: (MDS::rejoin_joint_start()+0x131) [0x4a8721]
9: (MDS::handle_mds_map(MMDSMap*)+0x2c4a) [0x4c253a]
10: (MDS::handle_core_message(Message*)+0x913) [0x4c4513]
11: (MDS::_dispatch(Message*)+0x2f) [0x4c45ef]
12: (MDS::ms_dispatch(Message*)+0x1fb) [0x4c628b]
13: (SimpleMessenger::dispatch_entry()+0x979) [0x7acb49]
14: (SimpleMessenger::DispatchThread::entry()+0xd) [0x7336ed]
15: (()+0x68ca) [0x7f5f437378ca]
16: (clone()+0x6d) [0x7f5f41fbf92d]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is
needed to interpret this.
--- begin dump of recent events ---
-194> 2012-05-22 12:02:02.673184 7f5f43b5d780 0 ceph version 0.46
(commit:cb7f1c9c7520848b0899b26440ac34a8acea58d1), process ceph-mds,
pid 23071
-193> 2012-05-22 12:02:02.673364 7f5f43b5d780 1 --
0.0.0.0:6800/23071 accepter.bind my_inst.addr is 0.0.0.0:6800/23071
need_addr=1
-192> 2012-05-22 12:02:02.678094 7f5f43b5d780 1 --
0.0.0.0:6800/23071 messenger.start
-191> 2012-05-22 12:02:02.678245 7f5f43b5d780 1 --
0.0.0.0:6800/23071 accepter.start
-190> 2012-05-22 12:02:02.679672 7f5f43b5d780 1 --
0.0.0.0:6800/23071 --> 10.3.0.12:6789/0 -- auth(proto 0 26 bytes epoch
0) v1 -- ?+0 0x13ea400 con 0x13ecdc0
-189> 2012-05-22 12:02:02.680105 7f5f43b5c700 1 --
10.3.0.12:6800/23071 learned my addr 10.3.0.12:6800/23071
-188> 2012-05-22 12:02:02.680390 7f5f3ecd1700 0 mds.-1.0
ms_handle_connect on 10.3.0.12:6789/0
-187> 2012-05-22 12:02:02.681402 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 1 ==== mon_map v1 ====
469+0+0 (56645397 0 0) 0x13eaa00 con 0x13ecdc0
-186> 2012-05-22 12:02:02.681529 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 2 ====
auth_reply(proto 1 0 Success) v1 ==== 24+0+0 (3086217166 0 0)
0x13ea800 con 0x13ecdc0
-185> 2012-05-22 12:02:02.681596 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 --
mon_subscribe({monmap=0+}) v2 -- ?+0 0x1404380 con 0x13ecdc0
-184> 2012-05-22 12:02:02.681932 7f5f43b5d780 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 -- mdsbeacon(6308/c up:boot
seq 1 v0) v2 -- ?+0 0x13f7c80 con 0x13ecdc0
-183> 2012-05-22 12:02:02.682060 7f5f43b5d780 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 --
mon_subscribe({monmap=2+,osdmap=0}) v2 -- ?+0 0x14041c0 con 0x13ecdc0
-182> 2012-05-22 12:02:02.682109 7f5f43b5d780 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 --
mon_subscribe({mdsmap=0+,monmap=2+,osdmap=0}) v2 -- ?+0 0x14048c0 con
0x13ecdc0
-181> 2012-05-22 12:02:02.682421 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 3 ==== mon_map v1 ====
469+0+0 (56645397 0 0) 0x1407600 con 0x13ecdc0
-180> 2012-05-22 12:02:02.682554 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 4 ====
mon_subscribe_ack(300s) v1 ==== 20+0+0 (311377444 0 0) 0x1404380 con
0x13ecdc0
-179> 2012-05-22 12:02:02.682978 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 5 ====
osd_map(234..234 src has 1..234) v3 ==== 19741+0+0 (3560848488 0 0)
0x1407400 con 0x13ecdc0
-178> 2012-05-22 12:02:02.683587 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 6 ====
mon_subscribe_ack(300s) v1 ==== 20+0+0 (311377444 0 0) 0x1404a80 con
0x13ecdc0
-177> 2012-05-22 12:02:02.683601 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 7 ==== mdsmap(e 52010)
v1 ==== 535+0+0 (2872786254 0 0) 0x1407200 con 0x13ecdc0
-176> 2012-05-22 12:02:02.683631 7f5f3ecd1700 5 mds.-1.0
handle_mds_map epoch 52010 from mon.2
-175> 2012-05-22 12:02:02.683818 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 8 ====
osd_map(234..234 src has 1..234) v3 ==== 19741+0+0 (3560848488 0 0)
0x1407000 con 0x13ecdc0
-174> 2012-05-22 12:02:02.683932 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 9 ====
mon_subscribe_ack(300s) v1 ==== 20+0+0 (311377444 0 0) 0x14041c0 con
0x13ecdc0
-173> 2012-05-22 12:02:02.768244 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 10 ==== mdsmap(e
52011) v1 ==== 733+0+0 (1289862739 0 0) 0x1407a00 con 0x13ecdc0
-172> 2012-05-22 12:02:02.768364 7f5f3ecd1700 5 mds.-1.-1
handle_mds_map epoch 52011 from mon.2
-171> 2012-05-22 12:02:02.768413 7f5f3ecd1700 1 mds.-1.0
handle_mds_map standby
-170> 2012-05-22 12:02:02.933902 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 11 ==== mdsmap(e
52012) v1 ==== 535+0+0 (3794450792 0 0) 0x1407800 con 0x13ecdc0
-169> 2012-05-22 12:02:02.933965 7f5f3ecd1700 5 mds.-1.0
handle_mds_map epoch 52012 from mon.2
-168> 2012-05-22 12:02:02.934007 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 mark_down 10.3.0.12:6800/23046 -- pipe dne
-167> 2012-05-22 12:02:02.934016 7f5f3ecd1700 1 mds.0.49
handle_mds_map i am now mds.0.49
-166> 2012-05-22 12:02:02.934030 7f5f3ecd1700 1 mds.0.49
handle_mds_map state change up:standby --> up:replay
-165> 2012-05-22 12:02:02.934040 7f5f3ecd1700 1 mds.0.49 replay_start
-164> 2012-05-22 12:02:02.934052 7f5f3ecd1700 1 mds.0.49 recovery set is
-163> 2012-05-22 12:02:02.934055 7f5f3ecd1700 1 mds.0.49 need
osdmap epoch 235, have 234
-162> 2012-05-22 12:02:02.934058 7f5f3ecd1700 1 mds.0.49 waiting
for osdmap 235 (which blacklists prior instance)
-161> 2012-05-22 12:02:02.934076 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 --
mon_subscribe({mdsmap=52013+,monmap=2+,osdmap=235}) v2 -- ?+0
0x14041c0 con 0x13ecdc0
-160> 2012-05-22 12:02:02.934154 7f5f3ecd1700 1 mds.0.cache
handle_mds_failure mds.0 : recovery peers are
-159> 2012-05-22 12:02:02.934184 7f5f3ecd1700 5 mds.0.migrator
handle_mds_failure_or_stop mds.0
-158> 2012-05-22 12:02:02.992970 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 12 ====
osd_map(235..235 src has 1..235) v3 ==== 300+0+0 (2376656173 0 0)
0x1407600 con 0x13ecdc0
-157> 2012-05-22 12:02:02.993145 7f5f3ecd1700 2 mds.0.49 boot_start
1: opening inotable
-156> 2012-05-22 12:02:02.993411 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:1
mds0_inotable [read 0~0] 1.b852b893) v4 -- ?+0 0x13e36c0 con 0x1408a00
-155> 2012-05-22 12:02:02.993471 7f5f3ecd1700 2 mds.0.49 boot_start
1: opening sessionmap
-154> 2012-05-22 12:02:02.993553 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:2
mds0_sessionmap [read 0~0] 1.3270c60b) v4 -- ?+0 0x13e3d80 con
0x1408a00
-153> 2012-05-22 12:02:02.993577 7f5f3ecd1700 2 mds.0.49 boot_start
1: opening anchor table
-152> 2012-05-22 12:02:02.993625 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:3
mds_anchortable [read 0~0] 1.a977f6a7) v4 -- ?+0 0x13e3900 con
0x1408a00
-151> 2012-05-22 12:02:02.993634 7f5f3ecd1700 2 mds.0.49 boot_start
1: opening snap table
-150> 2012-05-22 12:02:02.993671 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:4
mds_snaptable [read 0~0] 1.d90270ad) v4 -- ?+0 0x140d6c0 con 0x1408a00
-149> 2012-05-22 12:02:02.993680 7f5f3ecd1700 2 mds.0.49 boot_start
1: opening mds log
-148> 2012-05-22 12:02:02.993700 7f5f3ecd1700 5 mds.0.log open
discovering log bounds
-147> 2012-05-22 12:02:02.993792 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:5
200.00000000 [read 0~0] 1.844f3494) v4 -- ?+0 0x140d480 con 0x1408a00
-146> 2012-05-22 12:02:02.993826 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 13 ====
mon_subscribe_ack(300s) v1 ==== 20+0+0 (311377444 0 0) 0x140b380 con
0x13ecdc0
-145> 2012-05-22 12:02:02.994043 7f5f3ecd1700 0 mds.0.49
ms_handle_connect on 10.3.0.12:6801/1172
-144> 2012-05-22 12:02:02.995288 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 1 ====
osd_op_reply(1 mds0_inotable [read 0~29] = 0) v4 ==== 112+0+29
(3509020669 0 2080707671) 0x1407400 con 0x1408a00
-143> 2012-05-22 12:02:02.995518 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 2 ====
osd_op_reply(2 mds0_sessionmap [read 0~10591] = 0) v4 ==== 114+0+10591
(734241002 0 1640895633) 0x1407000 con 0x1408a00
-142> 2012-05-22 12:02:02.995836 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 3 ====
osd_op_reply(3 mds_anchortable [read 0~29] = 0) v4 ==== 114+0+29
(1868654419 0 218791405) 0x1407200 con 0x1408a00
-141> 2012-05-22 12:02:02.995890 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 4 ====
osd_op_reply(4 mds_snaptable [read 0~41] = 0) v4 ==== 112+0+41
(3594810684 0 2312406677) 0x1407e00 con 0x1408a00
-140> 2012-05-22 12:02:02.995940 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 5 ====
osd_op_reply(5 200.00000000 [read 0~84] = 0) v4 ==== 111+0+84
(3837001893 0 1130699602) 0x1407c00 con 0x1408a00
-139> 2012-05-22 12:02:02.996032 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:6
200.0000016d [stat 0~0] 1.6f7c9ad6 rwordered) v4 -- ?+0 0x140d480 con
0x1408a00
-138> 2012-05-22 12:02:02.996107 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:7
200.0000016e [stat 0~0] 1.9feb60a6 rwordered) v4 -- ?+0 0x140d6c0 con
0x1408a00
-137> 2012-05-22 12:02:02.996608 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 6 ====
osd_op_reply(6 200.0000016d [stat 0~0] = 0) v4 ==== 111+0+16
(1485433033 0 624451111) 0x1407a00 con 0x1408a00
-136> 2012-05-22 12:02:02.997170 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 7 ====
osd_op_reply(7 200.0000016e [stat 0~0] = 0) v4 ==== 111+0+16
(2013887546 0 3894377183) 0x1407000 con 0x1408a00
-135> 2012-05-22 12:02:02.997202 7f5f3ecd1700 2 mds.0.49 boot_start
2: loading/discovering base inodes
-134> 2012-05-22 12:02:02.997211 7f5f3ecd1700 0 mds.0.cache
creating system inode with ino:100
-133> 2012-05-22 12:02:02.999723 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:8
100.00000000 [getxattr inode] 1.c5265ab3) v4 -- ?+0 0x13e36c0 con
0x1408a00
-132> 2012-05-22 12:02:02.999788 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:9
100.00000000.inode [read 0~0] 1.85dde07f) v4 -- ?+0 0x13e3900 con
0x1408a00
-131> 2012-05-22 12:02:02.999804 7f5f3ecd1700 0 mds.0.cache
creating system inode with ino:1
-130> 2012-05-22 12:02:02.999874 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:10
1.00000000 [getxattr inode] 1.6b2cdaff) v4 -- ?+0 0x140db40 con
0x1408a00
-129> 2012-05-22 12:02:03.000142 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:11
1.00000000.inode [read 0~0] 1.232c0e14) v4 -- ?+0 0x140d900 con
0x1408a00
-128> 2012-05-22 12:02:03.000936 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 8 ====
osd_op_reply(9 100.00000000.inode [read 0~399] = 0) v4 ==== 117+0+399
(2159939521 0 4121830280) 0x1407400 con 0x1408a00
-127> 2012-05-22 12:02:03.001468 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 9 ====
osd_op_reply(8 100.00000000 [getxattr] = -61 (No data available)) v4
==== 111+0+0 (4127029859 0 0) 0x1407600 con 0x1408a00
-126> 2012-05-22 12:02:03.001669 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 10 ====
osd_op_reply(10 1.00000000 [getxattr] = -61 (No data available)) v4
==== 109+0+0 (1727840390 0 0) 0x1407800 con 0x1408a00
-125> 2012-05-22 12:02:03.001742 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 11 ====
osd_op_reply(11 1.00000000.inode [read 0~428] = 0) v4 ==== 115+0+428
(3364705558 0 715602140) 0x1407200 con 0x1408a00
-124> 2012-05-22 12:02:03.001809 7f5f3ecd1700 2 mds.0.49 boot_start
3: replaying mds log
-123> 2012-05-22 12:02:03.002198 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:12
200.0000014f [read 2535~4191769] 1.b79a8c0b) v4 -- ?+0 0x140d480 con
0x1408a00
-122> 2012-05-22 12:02:03.002290 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:13
200.00000150 [read 0~4194304] 1.23163b1d) v4 -- ?+0 0x13e36c0 con
0x1408a00
-121> 2012-05-22 12:02:03.004043 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:14
200.00000151 [read 0~4194304] 1.28b76431) v4 -- ?+0 0x140d6c0 con
0x1408a00
-120> 2012-05-22 12:02:03.004205 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:15
200.00000152 [read 0~4194304] 1.ae9bb683) v4 -- ?+0 0x140d480 con
0x1408a00
-119> 2012-05-22 12:02:03.004380 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:16
200.00000153 [read 0~4194304] 1.d9966785) v4 -- ?+0 0x140d900 con
0x1408a00
-118> 2012-05-22 12:02:03.004454 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:17
200.00000154 [read 0~4194304] 1.47f9bf13) v4 -- ?+0 0x140db40 con
0x1408a00
-117> 2012-05-22 12:02:03.004520 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:18
200.00000155 [read 0~4194304] 1.460264c4) v4 -- ?+0 0x13e3900 con
0x1408a00
-116> 2012-05-22 12:02:03.004582 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:19
200.00000156 [read 0~4194304] 1.cae377ec) v4 -- ?+0 0x13e36c0 con
0x1408a00
-115> 2012-05-22 12:02:03.004650 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:20
200.00000157 [read 0~4194304] 1.1c534f6b) v4 -- ?+0 0x140d6c0 con
0x1408a00
-114> 2012-05-22 12:02:03.004740 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:21
200.00000158 [read 0~4194304] 1.21f6fd52) v4 -- ?+0 0x143f900 con
0x1408a00
-113> 2012-05-22 12:02:03.031626 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 12 ====
osd_op_reply(12 200.0000014f [read 2535~4191769] = 0) v4 ====
111+0+4191769 (86938826 0 940254350) 0x1407600 con 0x1408a00
-112> 2012-05-22 12:02:03.049765 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 13 ====
osd_op_reply(13 200.00000150 [read 0~4194304] = 0) v4 ====
111+0+4194304 (2540809359 0 2765354474) 0x1407400 con 0x1408a00
-111> 2012-05-22 12:02:03.061435 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 14 ====
osd_op_reply(14 200.00000151 [read 0~4194304] = 0) v4 ====
111+0+4194304 (2370055404 0 728673944) 0x1407000 con 0x1408a00
-110> 2012-05-22 12:02:03.073952 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 15 ====
osd_op_reply(15 200.00000152 [read 0~4194304] = 0) v4 ====
111+0+4194304 (2835608127 0 4176800115) 0x1407a00 con 0x1408a00
-109> 2012-05-22 12:02:03.086138 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:22
200.00000159 [read 0~4194304] 1.11c4d2c4) v4 -- ?+0 0x143f480 con
0x1408a00
-108> 2012-05-22 12:02:03.087461 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 16 ====
osd_op_reply(16 200.00000153 [read 0~4194304] = 0) v4 ====
111+0+4194304 (414535972 0 2827888072) 0x1407c00 con 0x1408a00
-107> 2012-05-22 12:02:03.119482 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 17 ====
osd_op_reply(17 200.00000154 [read 0~4194304] = 0) v4 ====
111+0+4194304 (2490448686 0 1942553121) 0x1407e00 con 0x1408a00
-106> 2012-05-22 12:02:03.119562 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 18 ====
osd_op_reply(18 200.00000155 [read 0~4194304] = 0) v4 ====
111+0+4194304 (1664826329 0 2280396596) 0x143ee00 con 0x1408a00
-105> 2012-05-22 12:02:03.131469 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 19 ====
osd_op_reply(19 200.00000156 [read 0~4194304] = 0) v4 ====
111+0+4194304 (324288200 0 2843054375) 0x143ec00 con 0x1408a00
-104> 2012-05-22 12:02:03.139410 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:23
200.0000015a [read 0~4194304] 1.d46a5844) v4 -- ?+0 0x143f000 con
0x1408a00
-103> 2012-05-22 12:02:03.145585 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 20 ====
osd_op_reply(20 200.00000157 [read 0~4194304] = 0) v4 ====
111+0+4194304 (542705527 0 967023793) 0x143ea00 con 0x1408a00
-102> 2012-05-22 12:02:03.156508 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 21 ====
osd_op_reply(21 200.00000158 [read 0~4194304] = 0) v4 ====
111+0+4194304 (3296968726 0 3798599763) 0x143e800 con 0x1408a00
-101> 2012-05-22 12:02:03.172296 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 22 ====
osd_op_reply(22 200.00000159 [read 0~4194304] = 0) v4 ====
111+0+4194304 (2210915791 0 2737758750) 0x143e600 con 0x1408a00
-100> 2012-05-22 12:02:03.182754 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:24
200.0000015b [read 0~4194304] 1.a8a12f71) v4 -- ?+0 0x140d480 con
0x1408a00
-99> 2012-05-22 12:02:03.185018 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 23 ====
osd_op_reply(23 200.0000015a [read 0~4194304] = 0) v4 ====
111+0+4194304 (859847618 0 611094159) 0x143e400 con 0x1408a00
-98> 2012-05-22 12:02:03.205868 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 24 ====
osd_op_reply(24 200.0000015b [read 0~4194304] = 0) v4 ====
111+0+4194304 (541055975 0 524786588) 0x143e200 con 0x1408a00
-97> 2012-05-22 12:02:03.225090 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:25
200.0000015c [read 0~4194304] 1.941114d8) v4 -- ?+0 0x13e3900 con
0x1408a00
-96> 2012-05-22 12:02:03.242516 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 25 ====
osd_op_reply(25 200.0000015c [read 0~4194304] = 0) v4 ====
111+0+4194304 (1141303529 0 1957418634) 0x143e200 con 0x1408a00
-95> 2012-05-22 12:02:03.263094 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:26
200.0000015d [read 0~4194304] 1.bdfe9959) v4 -- ?+0 0x143fb40 con
0x1408a00
-94> 2012-05-22 12:02:03.278274 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 26 ====
osd_op_reply(26 200.0000015d [read 0~4194304] = 0) v4 ====
111+0+4194304 (3503869406 0 773787611) 0x143e400 con 0x1408a00
-93> 2012-05-22 12:02:03.300327 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:27
200.0000015e [read 0~4194304] 1.b8cf7266) v4 -- ?+0 0x140db40 con
0x1408a00
-92> 2012-05-22 12:02:03.316669 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 27 ====
osd_op_reply(27 200.0000015e [read 0~4194304] = 0) v4 ====
111+0+4194304 (1073368869 0 2950585796) 0x143e600 con 0x1408a00
-91> 2012-05-22 12:02:03.336096 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:28
200.0000015f [read 0~4194304] 1.2980b721) v4 -- ?+0 0x1ba9b40 con
0x1408a00
-90> 2012-05-22 12:02:03.352131 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 28 ====
osd_op_reply(28 200.0000015f [read 0~4194304] = 0) v4 ====
111+0+4194304 (3513547997 0 1851987047) 0x143e800 con 0x1408a00
-89> 2012-05-22 12:02:03.371923 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:29
200.00000160 [read 0~4194304] 1.574ae4ae) v4 -- ?+0 0x1ba96c0 con
0x1408a00
-88> 2012-05-22 12:02:03.388290 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 29 ====
osd_op_reply(29 200.00000160 [read 0~4194304] = 0) v4 ====
111+0+4194304 (2670366445 0 4080047592) 0x143ea00 con 0x1408a00
-87> 2012-05-22 12:02:03.410233 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:30
200.00000161 [read 0~4194304] 1.87287887) v4 -- ?+0 0x1ba9240 con
0x1408a00
-86> 2012-05-22 12:02:03.426379 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 30 ====
osd_op_reply(30 200.00000161 [read 0~4194304] = 0) v4 ====
111+0+4194304 (2306991298 0 2632960265) 0x143ec00 con 0x1408a00
-85> 2012-05-22 12:02:03.450460 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:31
200.00000162 [read 0~4194304] 1.f23e2d31) v4 -- ?+0 0x140db40 con
0x1408a00
-84> 2012-05-22 12:02:03.466463 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 31 ====
osd_op_reply(31 200.00000162 [read 0~4194304] = 0) v4 ====
111+0+4194304 (4169482190 0 1357295963) 0x143ee00 con 0x1408a00
-83> 2012-05-22 12:02:03.492735 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:32
200.00000163 [read 0~4194304] 1.ac437fe4) v4 -- ?+0 0x143fb40 con
0x1408a00
-82> 2012-05-22 12:02:03.528942 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:33
200.00000164 [read 0~4194304] 1.5a233b33) v4 -- ?+0 0x143f480 con
0x1408a00
-81> 2012-05-22 12:02:03.570058 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:34
200.00000165 [read 0~4194304] 1.1f8332c7) v4 -- ?+0 0x13e3900 con
0x1408a00
-80> 2012-05-22 12:02:03.570757 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 32 ====
osd_op_reply(32 200.00000163 [read 0~4194304] = 0) v4 ====
111+0+4194304 (2725338461 0 3594916529) 0x1d3ce00 con 0x1408a00
-79> 2012-05-22 12:02:03.589941 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 33 ====
osd_op_reply(33 200.00000164 [read 0~4194304] = 0) v4 ====
111+0+4194304 (988396741 0 694923933) 0x1d3cc00 con 0x1408a00
-78> 2012-05-22 12:02:03.594028 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 34 ====
osd_op_reply(34 200.00000165 [read 0~4194304] = 0) v4 ====
111+0+4194304 (894342962 0 1116835292) 0x1d3ca00 con 0x1408a00
-77> 2012-05-22 12:02:03.616937 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:35
200.00000166 [read 0~4194304] 1.8ce28c4a) v4 -- ?+0 0x1d43b40 con
0x1408a00
-76> 2012-05-22 12:02:03.633104 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 35 ====
osd_op_reply(35 200.00000166 [read 0~4194304] = 0) v4 ====
111+0+4194304 (34046407 0 554791290) 0x1d3c800 con 0x1408a00
-75> 2012-05-22 12:02:03.656933 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:36
200.00000167 [read 0~4194304] 1.7e245b6f) v4 -- ?+0 0x1d436c0 con
0x1408a00
-74> 2012-05-22 12:02:03.672729 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 36 ====
osd_op_reply(36 200.00000167 [read 0~4194304] = 0) v4 ====
111+0+4194304 (3542980681 0 3731006206) 0x1d3c600 con 0x1408a00
-73> 2012-05-22 12:02:03.694800 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:37
200.00000168 [read 0~4194304] 1.b1365376) v4 -- ?+0 0x1d43240 con
0x1408a00
-72> 2012-05-22 12:02:03.713056 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 37 ====
osd_op_reply(37 200.00000168 [read 0~4194304] = 0) v4 ====
111+0+4194304 (3143521032 0 2534577188) 0x1d3c400 con 0x1408a00
-71> 2012-05-22 12:02:03.732734 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:38
200.00000169 [read 0~4194304] 1.ff0405d0) v4 -- ?+0 0x1d43b40 con
0x1408a00
-70> 2012-05-22 12:02:03.751450 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 38 ====
osd_op_reply(38 200.00000169 [read 0~4194304] = 0) v4 ====
111+0+4194304 (733149638 0 738384784) 0x1d3c200 con 0x1408a00
-69> 2012-05-22 12:02:03.770040 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:39
200.0000016a [read 0~4194304] 1.3f32f1a0) v4 -- ?+0 0x143f480 con
0x1408a00
-68> 2012-05-22 12:02:03.787041 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 39 ====
osd_op_reply(39 200.0000016a [read 0~4194304] = 0) v4 ====
111+0+4194304 (79880031 0 463711875) 0x1d3c000 con 0x1408a00
-67> 2012-05-22 12:02:03.807842 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:40
200.0000016b [read 0~4194304] 1.c299cbd3) v4 -- ?+0 0x140db40 con
0x1408a00
-66> 2012-05-22 12:02:03.824629 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 40 ====
osd_op_reply(40 200.0000016b [read 0~4194304] = 0) v4 ====
111+0+4194304 (707054799 0 1356117031) 0x1d3cc00 con 0x1408a00
-65> 2012-05-22 12:02:03.845870 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:41
200.0000016c [read 0~4194304] 1.41d6438b) v4 -- ?+0 0x1ba96c0 con
0x1408a00
-64> 2012-05-22 12:02:03.862209 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 41 ====
osd_op_reply(41 200.0000016c [read 0~4194304] = 0) v4 ====
111+0+4194304 (78005920 0 1848623926) 0x1d3ce00 con 0x1408a00
-63> 2012-05-22 12:02:03.882715 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:42
200.0000016d [read 0~4194304] 1.6f7c9ad6) v4 -- ?+0 0x1d58d80 con
0x1408a00
-62> 2012-05-22 12:02:03.901124 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 42 ====
osd_op_reply(42 200.0000016d [read 0~4194304] = 0) v4 ====
111+0+4194304 (3681601409 0 3284364392) 0x143ee00 con 0x1408a00
-61> 2012-05-22 12:02:03.921699 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:43
200.0000016e [read 0~149004] 1.9feb60a6) v4 -- ?+0 0x1d58900 con
0x1408a00
-60> 2012-05-22 12:02:03.923308 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 43 ====
osd_op_reply(43 200.0000016e [read 0~149004] = 0) v4 ==== 111+0+149004
(188018409 0 1584225691) 0x143ec00 con 0x1408a00
-59> 2012-05-22 12:02:04.270213 7f5f3c9ca700 1 mds.0.49 replay_done
-58> 2012-05-22 12:02:04.270248 7f5f3c9ca700 1 mds.0.49 making mds
journal writeable
-57> 2012-05-22 12:02:04.270338 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:44
200.0000016e [zero 149004~4045300] 1.9feb60a6) v4 -- ?+0 0x1ea56c0 con
0x1408a00
-56> 2012-05-22 12:02:04.270415 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:45
200.0000016f [delete] 1.e6816672) v4 -- ?+0 0x1ea5480 con 0x1408a00
-55> 2012-05-22 12:02:04.270488 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:46
200.00000170 [delete] 1.3e8426cd) v4 -- ?+0 0x1ea5240 con 0x1408a00
-54> 2012-05-22 12:02:04.270569 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:47
200.00000171 [delete] 1.75986202) v4 -- ?+0 0x1ea5000 con 0x1408a00
-53> 2012-05-22 12:02:04.270641 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:48
200.00000172 [delete] 1.d3c077fe) v4 -- ?+0 0x1ea56c0 con 0x1408a00
-52> 2012-05-22 12:02:04.270796 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6801/1172 -- osd_op(mds.0.49:49
200.00000173 [delete] 1.3b1f2284) v4 -- ?+0 0x1d58900 con 0x1408a00
-51> 2012-05-22 12:02:04.270893 7f5f3c9ca700 2 mds.0.49 i am
alone, moving to state reconnect
-50> 2012-05-22 12:02:04.270899 7f5f3c9ca700 3 mds.0.49
request_state up:reconnect
-49> 2012-05-22 12:02:04.270916 7f5f3c9ca700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 -- mdsbeacon(6308/c
up:reconnect seq 2 v52012) v2 -- ?+0 0x140c280 con 0x13ecdc0
-48> 2012-05-22 12:02:04.271925 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 44 ====
osd_op_reply(45 200.0000016f [delete] ondisk = -2 (No such file or
directory)) v4 ==== 111+0+0 (3525298709 0 0) 0x143ea00 con 0x1408a00
-47> 2012-05-22 12:02:04.272089 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 45 ====
osd_op_reply(46 200.00000170 [delete] ondisk = -2 (No such file or
directory)) v4 ==== 111+0+0 (1763128336 0 0) 0x143e800 con 0x1408a00
-46> 2012-05-22 12:02:04.272129 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 46 ====
osd_op_reply(47 200.00000171 [delete] ondisk = -2 (No such file or
directory)) v4 ==== 111+0+0 (1713780953 0 0) 0x143e600 con 0x1408a00
-45> 2012-05-22 12:02:04.272151 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 47 ====
osd_op_reply(48 200.00000172 [delete] ondisk = -2 (No such file or
directory)) v4 ==== 111+0+0 (1956823652 0 0) 0x143e400 con 0x1408a00
-44> 2012-05-22 12:02:04.272206 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 48 ====
osd_op_reply(49 200.00000173 [delete] ondisk = -2 (No such file or
directory)) v4 ==== 111+0+0 (1397982303 0 0) 0x143e200 con 0x1408a00
-43> 2012-05-22 12:02:04.274577 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== osd.2 10.3.0.12:6801/1172 49 ====
osd_op_reply(44 200.0000016e [truncate 149004] ondisk = 0) v4 ====
111+0+0 (623816276 0 0) 0x143ec00 con 0x1408a00
-42> 2012-05-22 12:02:04.358132 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 14 ==== mdsmap(e
52013) v1 ==== 535+0+0 (132891602 0 0) 0x13eae00 con 0x13ecdc0
-41> 2012-05-22 12:02:04.358253 7f5f3ecd1700 5 mds.0.49
handle_mds_map epoch 52013 from mon.2
-40> 2012-05-22 12:02:04.358293 7f5f3ecd1700 1 mds.0.49
handle_mds_map i am now mds.0.49
-39> 2012-05-22 12:02:04.358299 7f5f3ecd1700 1 mds.0.49
handle_mds_map state change up:replay --> up:reconnect
-38> 2012-05-22 12:02:04.358314 7f5f3ecd1700 1 mds.0.49 reconnect_start
-37> 2012-05-22 12:02:04.358319 7f5f3ecd1700 1 mds.0.49 reopen_log
-36> 2012-05-22 12:02:04.358340 7f5f3ecd1700 1 mds.0.server
reconnect_clients -- 2 sessions
-35> 2012-05-22 12:02:04.358474 7f5f3ecd1700 5 mds.0.bal rebalance done
-34> 2012-05-22 12:02:08.271081 7f5f3d3cd700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 -- mdsbeacon(6308/c
up:reconnect seq 3 v52013) v2 -- ?+0 0x13f7c80 con 0x13ecdc0
-33> 2012-05-22 12:02:08.272677 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 15 ====
mdsbeacon(6308/c up:reconnect seq 3 v52013) v2 ==== 103+0+0
(3383220134 0 0) 0x140c280 con 0x13ecdc0
-32> 2012-05-22 12:02:12.271359 7f5f3d3cd700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 -- mdsbeacon(6308/c
up:reconnect seq 4 v52013) v2 -- ?+0 0x140c780 con 0x13ecdc0
-31> 2012-05-22 12:02:12.272900 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 16 ====
mdsbeacon(6308/c up:reconnect seq 4 v52013) v2 ==== 103+0+0
(2744505186 0 0) 0x140cc80 con 0x13ecdc0
-30> 2012-05-22 12:02:16.271690 7f5f3d3cd700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 -- mdsbeacon(6308/c
up:reconnect seq 5 v52013) v2 -- ?+0 0x140c500 con 0x13ecdc0
-29> 2012-05-22 12:02:16.273021 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 17 ====
mdsbeacon(6308/c up:reconnect seq 5 v52013) v2 ==== 103+0+0
(3669798405 0 0) 0x140ca00 con 0x13ecdc0
-28> 2012-05-22 12:02:20.272061 7f5f3d3cd700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 -- mdsbeacon(6308/c
up:reconnect seq 6 v52013) v2 -- ?+0 0x140cc80 con 0x13ecdc0
-27> 2012-05-22 12:02:20.273524 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 18 ====
mdsbeacon(6308/c up:reconnect seq 6 v52013) v2 ==== 103+0+0
(1372006828 0 0) 0x140c500 con 0x13ecdc0
-26> 2012-05-22 12:02:24.272320 7f5f3d3cd700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 -- mdsbeacon(6308/c
up:reconnect seq 7 v52013) v2 -- ?+0 0x140c280 con 0x13ecdc0
-25> 2012-05-22 12:02:24.273966 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 19 ====
mdsbeacon(6308/c up:reconnect seq 7 v52013) v2 ==== 103+0+0 (686707915
0 0) 0x140c780 con 0x13ecdc0
-24> 2012-05-22 12:02:28.272580 7f5f3d3cd700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 -- mdsbeacon(6308/c
up:reconnect seq 8 v52013) v2 -- ?+0 0x13f7c80 con 0x13ecdc0
-23> 2012-05-22 12:02:28.273963 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 20 ====
mdsbeacon(6308/c up:reconnect seq 8 v52013) v2 ==== 103+0+0
(2242060324 0 0) 0x140ca00 con 0x13ecdc0
-22> 2012-05-22 12:02:32.272813 7f5f3d3cd700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 -- mdsbeacon(6308/c
up:reconnect seq 9 v52013) v2 -- ?+0 0x1d9c780 con 0x13ecdc0
-21> 2012-05-22 12:02:32.274428 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 21 ====
mdsbeacon(6308/c up:reconnect seq 9 v52013) v2 ==== 103+0+0
(4236926275 0 0) 0x1d9c780 con 0x13ecdc0
-20> 2012-05-22 12:02:36.273024 7f5f3d3cd700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 -- mdsbeacon(6308/c
up:reconnect seq 10 v52013) v2 -- ?+0 0x1d9c500 con 0x13ecdc0
-19> 2012-05-22 12:02:36.274520 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 22 ====
mdsbeacon(6308/c up:reconnect seq 10 v52013) v2 ==== 103+0+0
(2012338922 0 0) 0x13f7c80 con 0x13ecdc0
-18> 2012-05-22 12:02:40.273243 7f5f3d3cd700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 -- mdsbeacon(6308/c
up:reconnect seq 11 v52013) v2 -- ?+0 0x1d9c280 con 0x13ecdc0
-17> 2012-05-22 12:02:40.274602 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 23 ====
mdsbeacon(6308/c up:reconnect seq 11 v52013) v2 ==== 103+0+0
(249079693 0 0) 0x140c280 con 0x13ecdc0
-16> 2012-05-22 12:02:44.273455 7f5f3d3cd700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 -- mdsbeacon(6308/c
up:reconnect seq 12 v52013) v2 -- ?+0 0x1d9c000 con 0x13ecdc0
-15> 2012-05-22 12:02:44.274917 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 24 ====
mdsbeacon(6308/c up:reconnect seq 12 v52013) v2 ==== 103+0+0
(1693098825 0 0) 0x140cc80 con 0x13ecdc0
-14> 2012-05-22 12:02:48.273651 7f5f3d3cd700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 -- mdsbeacon(6308/c
up:reconnect seq 13 v52013) v2 -- ?+0 0x1d9ca00 con 0x13ecdc0
-13> 2012-05-22 12:02:48.275240 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 25 ====
mdsbeacon(6308/c up:reconnect seq 13 v52013) v2 ==== 103+0+0
(499375662 0 0) 0x1d9cc80 con 0x13ecdc0
-12> 2012-05-22 12:02:52.273831 7f5f3d3cd700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 -- mdsbeacon(6308/c
up:reconnect seq 14 v52013) v2 -- ?+0 0x1d9c780 con 0x13ecdc0
-11> 2012-05-22 12:02:52.275198 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 26 ====
mdsbeacon(6308/c up:reconnect seq 14 v52013) v2 ==== 103+0+0
(2528663943 0 0) 0x1d9c780 con 0x13ecdc0
-10> 2012-05-22 12:02:52.683463 7f5f3d3cd700 1 mds.0.server
reconnect gave up on client.4114 10.3.0.11:0/32195
-9> 2012-05-22 12:02:52.683505 7f5f3d3cd700 1 mds.0.server
reconnect gave up on client.5099 10.3.0.12:0/773
-8> 2012-05-22 12:02:52.683527 7f5f3d3cd700 1 mds.0.49 reconnect_done
-7> 2012-05-22 12:02:52.683541 7f5f3d3cd700 3 mds.0.49
request_state up:rejoin
-6> 2012-05-22 12:02:52.683570 7f5f3d3cd700 1 --
10.3.0.12:6800/23071 --> 10.3.0.12:6789/0 -- mdsbeacon(6308/c
up:rejoin seq 15 v52013) v2 -- ?+0 0x140ca00 con 0x13ecdc0
-5> 2012-05-22 12:02:53.138079 7f5f3ecd1700 1 --
10.3.0.12:6800/23071 <== mon.2 10.3.0.12:6789/0 27 ==== mdsmap(e
52014) v1 ==== 535+0+0 (780151091 0 0) 0x13ea800 con 0x13ecdc0
-4> 2012-05-22 12:02:53.138146 7f5f3ecd1700 5 mds.0.49
handle_mds_map epoch 52014 from mon.2
-3> 2012-05-22 12:02:53.138192 7f5f3ecd1700 1 mds.0.49
handle_mds_map i am now mds.0.49
-2> 2012-05-22 12:02:53.138198 7f5f3ecd1700 1 mds.0.49
handle_mds_map state change up:reconnect --> up:rejoin
-1> 2012-05-22 12:02:53.138204 7f5f3ecd1700 1 mds.0.49 rejoin_joint_start
0> 2012-05-22 12:02:53.140710 7f5f3ecd1700 -1 *** Caught signal
(Segmentation fault) **
in thread 7f5f3ecd1700
ceph version 0.46 (commit:cb7f1c9c7520848b0899b26440ac34a8acea58d1)
1: ceph-mds() [0x814279]
2: (()+0xeff0) [0x7f5f4373fff0]
3: (SnapRealm::have_past_parents_open(snapid_t, snapid_t)+0x4f) [0x6cb5ef]
4: (MDCache::check_realm_past_parents(SnapRealm*)+0x2b) [0x55d58b]
5: (MDCache::choose_lock_states_and_reconnect_caps()+0x29c) [0x572eec]
6: (MDCache::rejoin_gather_finish()+0x90) [0x5931a0]
7: (MDCache::rejoin_send_rejoins()+0x2c05) [0x59b9d5]
8: (MDS::rejoin_joint_start()+0x131) [0x4a8721]
9: (MDS::handle_mds_map(MMDSMap*)+0x2c4a) [0x4c253a]
10: (MDS::handle_core_message(Message*)+0x913) [0x4c4513]
11: (MDS::_dispatch(Message*)+0x2f) [0x4c45ef]
12: (MDS::ms_dispatch(Message*)+0x1fb) [0x4c628b]
13: (SimpleMessenger::dispatch_entry()+0x979) [0x7acb49]
14: (SimpleMessenger::DispatchThread::entry()+0xd) [0x7336ed]
15: (()+0x68ca) [0x7f5f437378ca]
16: (clone()+0x6d) [0x7f5f41fbf92d]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is
needed to interpret this.
--- end dump of recent events ---
snip
I am not quite sure on how to get you the coredump infos. I installed
all ceph-dbg packages and executed:
gdb /usr/bin/ceph-mds core
snip
GNU gdb (GDB) 7.0.1-debian
Copyright (C) 2009 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/bin/ceph-mds...Reading symbols from
/usr/lib/debug/usr/bin/ceph-mds...done.
(no debugging symbols found)...done.
[New Thread 22980]
[New Thread 22984]
[New Thread 22986]
[New Thread 22979]
[New Thread 22970]
[New Thread 22981]
[New Thread 22971]
[New Thread 22976]
[New Thread 22973]
[New Thread 22975]
[New Thread 22974]
[New Thread 22972]
[New Thread 22978]
[New Thread 22982]
warning: Can't read pathname for load map: Input/output error.
Reading symbols from /lib/libpthread.so.0...(no debugging symbols found)...done.
Loaded symbols for /lib/libpthread.so.0
Reading symbols from /usr/lib/libcrypto++.so.8...(no debugging symbols
found)...done.
Loaded symbols for /usr/lib/libcrypto++.so.8
Reading symbols from /lib/libuuid.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib/libuuid.so.1
Reading symbols from /lib/librt.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib/librt.so.1
Reading symbols from /usr/lib/libtcmalloc.so.0...(no debugging symbols
found)...done.
Loaded symbols for /usr/lib/libtcmalloc.so.0
Reading symbols from /usr/lib/libstdc++.so.6...(no debugging symbols
found)...done.
Loaded symbols for /usr/lib/libstdc++.so.6
Reading symbols from /lib/libm.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib/libm.so.6
Reading symbols from /lib/libgcc_s.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib/libgcc_s.so.1
Reading symbols from /lib/libc.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib/libc.so.6
Reading symbols from /lib64/ld-linux-x86-64.so.2...(no debugging
symbols found)...done.
Loaded symbols for /lib64/ld-linux-x86-64.so.2
Reading symbols from /usr/lib/libunwind.so.7...(no debugging symbols
found)...done.
Loaded symbols for /usr/lib/libunwind.so.7
Core was generated by `/usr/bin/ceph-mds -i c --pid-file
/var/run/ceph/mds.c.pid -c /etc/ceph/ceph.con'.
Program terminated with signal 11, Segmentation fault.
#0 0x00007f10c00d2ebb in raise () from /lib/libpthread.so.0
snip
2012/5/21 Gregory Farnum <greg@xxxxxxxxxxx>:
> On Mon, May 21, 2012 at 5:38 AM, Felix Feinhals
> <ff@xxxxxxxxxxxxxxxxxxxxxxx> wrote:
>> Hi Josh,
>>
>> i quoted the trace and some other stats in my first email, maybe it
>> got stuck in the spam filters.
>> Well next try:
>>
>> snip
>>
>> -3> 2012-05-10 14:52:29.509940 7fb1c9351700 1 mds.0.40 handle_mds_map
>> i am now mds.0.40
>> -2> 2012-05-10 14:52:29.509956 7fb1c9351700 1 mds.0.40 handle_mds_map
>> state change up:reconnect --> up:rejoin
>> -1> 2012-05-10 14:52:29.509963 7fb1c9351700 1 mds.0.40 rejoin_joint_start
>> 0> 2012-05-10 14:52:29.512503 7fb1c9351700 -1 *** Caught signal
>> (Segmentation fault) **
>> in thread 7fb1c9351700
>>
>> ceph version 0.46 (commit:cb7f1c9c7520848b0899b26440ac34a8acea58d1)
>> 1: ceph-mds() [0x814279]
>> 2: (()+0xeff0) [0x7fb1cddbfff0]
>> 3: (SnapRealm::have_past_parents_open(snapid_t, snapid_t)+0x4f) [0x6cb5ef]
>> 4: (MDCache::check_realm_past_parents(SnapRealm*)+0x2b) [0x55d58b]
>> 5: (MDCache::choose_lock_states_and_reconnect_caps()+0x29c) [0x572eec]
>> 6: (MDCache::rejoin_gather_finish()+0x90) [0x5931a0]
>> 7: (MDCache::rejoin_send_rejoins()+0x2c05) [0x59b9d5]
>> 8: (MDS::rejoin_joint_start()+0x131) [0x4a8721]
>> 9: (MDS::handle_mds_map(MMDSMap*)+0x2c4a) [0x4c253a]
>> 10: (MDS::handle_core_message(Message*)+0x913) [0x4c4513]
>> 11: (MDS::_dispatch(Message*)+0x2f) [0x4c45ef]
>> 12: (MDS::ms_dispatch(Message*)+0x1fb) [0x4c628b]
>> 13: (SimpleMessenger::dispatch_entry()+0x979) [0x7acb49]
>> 14: (SimpleMessenger::DispatchThread::entry()+0xd) [0x7336ed]
>> 15: (()+0x68ca) [0x7fb1cddb78ca]
>> 16: (clone()+0x6d) [0x7fb1cc63f92d]
>
> There's nothing obvious here — can you run gdb on the core and get
> another backtrace and the info from levels 3-5?
>
>> snip
>>
>> I though ceph chooses which MDS is active and which is standby, i just
>> have 3 in the cluster config:
> Yes, it does — if you don't increase the number of allowed MDSes
> you'll just get one of them active.
> -Greg
--
To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
