Project

General

Profile

Bug #3593 » alpha.log

Matthew Via, 12/08/2012 10:40 AM

 
-336> 2012-12-08 13:28:34.549902 7f7eb89cf700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb067ec10 sd=36 :59229 pgs=1670 cs=1 l=1).writer error sending 0x7f7eb066a340, 32: Broken pipe
-335> 2012-12-08 13:28:34.549921 7f7eb89cf700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb067ec10 sd=36 :59229 pgs=1670 cs=1 l=1).fault 32: Broken pipe
-334> 2012-12-08 13:28:34.549978 7f7eb8bd1700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb067d650 sd=35 :51864 pgs=630 cs=1 l=1).do_sendmsg error Broken pipe
-333> 2012-12-08 13:28:34.550030 7f7eb8bd1700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb067d650 sd=35 :51864 pgs=630 cs=1 l=1).writer error sending 0x7f7eb06f09c0, 32: Broken pipe
-332> 2012-12-08 13:28:34.550051 7f7eb8bd1700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb067d650 sd=35 :51864 pgs=630 cs=1 l=1).fault 32: Broken pipe
-331> 2012-12-08 13:28:34.550132 7f7eb8fd5700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb0687c60 sd=34 :59227 pgs=1669 cs=1 l=1).do_sendmsg error Broken pipe
-330> 2012-12-08 13:28:34.550161 7f7eb8fd5700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb0687c60 sd=34 :59227 pgs=1669 cs=1 l=1).writer error sending 0x7f7eb06ec200, 32: Broken pipe
-329> 2012-12-08 13:28:34.550180 7f7eb8fd5700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb0687c60 sd=34 :59227 pgs=1669 cs=1 l=1).fault 32: Broken pipe
-328> 2012-12-08 13:28:34.550238 7f7eb93d9700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb0602b70 sd=31 :59219 pgs=1668 cs=1 l=1).do_sendmsg error Broken pipe
-327> 2012-12-08 13:28:34.550312 7f7eb93d9700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb0602b70 sd=31 :59219 pgs=1668 cs=1 l=1).writer error sending 0x7f7eb0605b00, 32: Broken pipe
-326> 2012-12-08 13:28:34.550333 7f7eb93d9700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb0602b70 sd=31 :59219 pgs=1668 cs=1 l=1).fault 32: Broken pipe
-325> 2012-12-08 13:28:34.550391 7f7eb97dd700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb05ff900 sd=29 :51853 pgs=625 cs=1 l=1).do_sendmsg error Broken pipe
-324> 2012-12-08 13:28:34.550417 7f7eb97dd700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb05ff900 sd=29 :51853 pgs=625 cs=1 l=1).writer error sending 0x7f7eb05ffc90, 32: Broken pipe
-323> 2012-12-08 13:28:34.550435 7f7eb97dd700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb05ff900 sd=29 :51853 pgs=625 cs=1 l=1).fault 32: Broken pipe
-322> 2012-12-08 13:28:34.550491 7f7eb99df700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb0647d80 sd=28 :59216 pgs=1667 cs=1 l=1).do_sendmsg error Broken pipe
-321> 2012-12-08 13:28:34.550518 7f7eb99df700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb0647d80 sd=28 :59216 pgs=1667 cs=1 l=1).writer error sending 0x7f7eb05fb090, 32: Broken pipe
-320> 2012-12-08 13:28:34.550537 7f7eb99df700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb0647d80 sd=28 :59216 pgs=1667 cs=1 l=1).fault 32: Broken pipe
-319> 2012-12-08 13:28:34.550597 7f7eb9be1700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.82:6789/0 pipe(0x7f7eb05fe280 sd=27 :43646 pgs=2128 cs=1 l=1).do_sendmsg error Broken pipe
-318> 2012-12-08 13:28:34.550624 7f7eb9be1700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.82:6789/0 pipe(0x7f7eb05fe280 sd=27 :43646 pgs=2128 cs=1 l=1).writer error sending 0x7f7eb05fd9b0, 32: Broken pipe
-317> 2012-12-08 13:28:34.550644 7f7eb9be1700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.82:6789/0 pipe(0x7f7eb05fe280 sd=27 :43646 pgs=2128 cs=1 l=1).fault 32: Broken pipe
-316> 2012-12-08 13:28:34.550700 7f7eb9de3700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb05fbf40 sd=26 :59214 pgs=1666 cs=1 l=1).do_sendmsg error Broken pipe
-315> 2012-12-08 13:28:34.550799 7f7eb9de3700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb05fbf40 sd=26 :59214 pgs=1666 cs=1 l=1).writer error sending 0x7f7eb05fc520, 32: Broken pipe
-314> 2012-12-08 13:28:34.550819 7f7eb9de3700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb05fbf40 sd=26 :59214 pgs=1666 cs=1 l=1).fault 32: Broken pipe
-313> 2012-12-08 13:28:34.550824 7f7ec411e700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb05f5b60 sd=16 :51847 pgs=623 cs=1 l=1).do_sendmsg error Broken pipe
-312> 2012-12-08 13:28:34.550872 7f7ec411e700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb05f5b60 sd=16 :51847 pgs=623 cs=1 l=1).writer error sending 0x7f7eb05f9330, 32: Broken pipe
-311> 2012-12-08 13:28:34.550915 7f7ec411e700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb05f5b60 sd=16 :51847 pgs=623 cs=1 l=1).fault 32: Broken pipe
-310> 2012-12-08 13:28:34.550997 7f7eb9ee4700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb05f8620 sd=25 :51849 pgs=624 cs=1 l=1).do_sendmsg error Broken pipe
-309> 2012-12-08 13:28:34.551057 7f7eb9ee4700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb05f8620 sd=25 :51849 pgs=624 cs=1 l=1).writer error sending 0x7f7eb0647690, 32: Broken pipe
-308> 2012-12-08 13:28:34.551077 7f7eb9ee4700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb05f8620 sd=25 :51849 pgs=624 cs=1 l=1).fault 32: Broken pipe
-307> 2012-12-08 13:28:34.550702 7f7eba1e7700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.82:6789/0 pipe(0x7f7eb31e1a80 sd=24 :43641 pgs=2127 cs=1 l=1).do_sendmsg error Broken pipe
-306> 2012-12-08 13:28:34.551183 7f7eba1e7700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.82:6789/0 pipe(0x7f7eb31e1a80 sd=24 :43641 pgs=2127 cs=1 l=1).writer error sending 0x7f7eb064f990, 32: Broken pipe
-305> 2012-12-08 13:28:34.551216 7f7eba1e7700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.82:6789/0 pipe(0x7f7eb31e1a80 sd=24 :43641 pgs=2127 cs=1 l=1).fault 32: Broken pipe
-304> 2012-12-08 13:28:35.018106 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== mon.2 192.168.2.82:6789/0 1 ==== auth_reply(proto 1 0 Success) v1 ==== 24+0+0 (1196077047 0 0) 0x7f7e94000ec0 con 0x7f7eb0668680
-303> 2012-12-08 13:28:35.018217 7f7ebdffb700 10 monclient: _send_mon_message to mon.2 at 192.168.2.82:6789/0
-302> 2012-12-08 13:28:35.018230 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.82:6789/0 -- mon_subscribe({mdsmap=3921+,monmap=2+,osdmap=938}) v2 -- ?+0 0x7f7eb06ad640 con 0x7f7eb0668680
-301> 2012-12-08 13:28:34.117216 7f7e984fd700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb0613cf0 sd=49 :0 pgs=0 cs=0 l=1).connect error 192.168.2.80:6789/0, 103: Software caused connection abort
-300> 2012-12-08 13:28:35.141080 7f7e984fd700 3 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb0613cf0 sd=49 :0 pgs=0 cs=0 l=1).connect fault, but state = closed != connecting, stopping
-299> 2012-12-08 13:28:35.152972 7f7ebdffb700 10 monclient: _check_auth_rotating renewing rotating keys (they expired before 2012-12-08 13:28:05.152967)
-298> 2012-12-08 13:28:35.154725 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== mon.2 192.168.2.82:6789/0 2 ==== osd_map(938..938 src has 437..938) v3 ==== 452+0+0 (2314856985 0 0) 0x7f7e940011c0 con 0x7f7eb0668680
-297> 2012-12-08 13:28:35.155066 7f7ebdffb700 10 mds.0.snap check_osd_map need_to_purge={}
-296> 2012-12-08 13:28:35.171401 7f7ebdffb700 5 mds.0.73 is_laggy 33.569115 > 15 since last acked beacon
-295> 2012-12-08 13:28:35.171501 7f7ebdffb700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-294> 2012-12-08 13:28:35.171511 7f7ebdffb700 10 monclient: _reopen_session
-293> 2012-12-08 13:28:35.171521 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb0668680 -- 0x7f7eb0668440
-292> 2012-12-08 13:28:35.171736 7f7ebdffb700 10 monclient: _pick_new_mon picked mon.1 con 0x7f7eb05fee20 addr 192.168.2.81:6789/0
-291> 2012-12-08 13:28:35.171837 7f7ebdffb700 10 monclient: _send_mon_message to mon.1 at 192.168.2.81:6789/0
-290> 2012-12-08 13:28:35.171860 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.81:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7eb1dcb0b0 con 0x7f7eb05fee20
-289> 2012-12-08 13:28:35.171882 7f7ebdffb700 10 monclient: renew_subs
-288> 2012-12-08 13:28:35.171913 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== mon.2 192.168.2.82:6789/0 3 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0 (2675486518 0 0) 0x7f7e94001470 con 0x7f7eb0668680
-287> 2012-12-08 13:28:35.171962 7f7ebdffb700 10 monclient: discarding stray monitor message mon_subscribe_ack(300s) v1
-286> 2012-12-08 13:28:35.172130 7f7e79676700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.82:6789/0 pipe(0x7f7eb0668440 sd=53 :43683 pgs=2135 cs=1 l=1).reader couldn't read tag, Success
-285> 2012-12-08 13:28:35.172173 7f7e79676700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.82:6789/0 pipe(0x7f7eb0668440 sd=53 :43683 pgs=2135 cs=1 l=1).fault 0: Success
-284> 2012-12-08 13:28:35.173530 7f7eb92d8700 10 mds.0.73 MDS::ms_get_authorizer type=mon
-283> 2012-12-08 13:28:35.174130 7f7ebdffb700 0 mds.0.73 ms_handle_connect on 192.168.2.81:6789/0
-282> 2012-12-08 13:28:35.258431 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== mon.1 192.168.2.81:6789/0 1 ==== auth_reply(proto 1 0 Success) v1 ==== 24+0+0 (1196077047 0 0) 0x7f7e88001c90 con 0x7f7eb05fee20
-281> 2012-12-08 13:28:35.258534 7f7ebdffb700 10 monclient: _send_mon_message to mon.1 at 192.168.2.81:6789/0
-280> 2012-12-08 13:28:35.258550 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.81:6789/0 -- mon_subscribe({mdsmap=3921+,monmap=2+}) v2 -- ?+0 0x7f7eb05fd190 con 0x7f7eb05fee20
-279> 2012-12-08 13:28:35.258663 7f7ebdffb700 10 monclient: _check_auth_rotating renewing rotating keys (they expired before 2012-12-08 13:28:05.258661)
-278> 2012-12-08 13:28:35.267069 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== mon.1 192.168.2.81:6789/0 2 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0 (2675486518 0 0) 0x7f7e88001c90 con 0x7f7eb05fee20
-277> 2012-12-08 13:28:35.267106 7f7ebdffb700 10 monclient: handle_subscribe_ack sent 2012-12-08 13:28:32.218785 renew after 2012-12-08 13:31:02.218785
-276> 2012-12-08 13:28:35.351275 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== osd.1 192.168.2.80:6804/3448 95 ==== osd_op_reply(711 1000004acc4.000000f2 [delete] ondisk = 0) v4 ==== 119+0+0 (1973361490 0 0) 0x7f7e80001440 con 0x7f7eb0046250
-275> 2012-12-08 13:28:35.351471 7f7ebdffb700 5 mds.0.73 is_laggy 33.749186 > 15 since last acked beacon
-274> 2012-12-08 13:28:35.351508 7f7ebdffb700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-273> 2012-12-08 13:28:35.351515 7f7ebdffb700 10 monclient: _reopen_session
-272> 2012-12-08 13:28:35.351525 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb05fee20 -- 0x7f7eb0681cc0
-271> 2012-12-08 13:28:35.351724 7f7ebdffb700 10 monclient: _pick_new_mon picked mon.0 con 0x7f7eb0686b40 addr 192.168.2.80:6789/0
-270> 2012-12-08 13:28:35.351777 7f7ebdffb700 10 monclient: _send_mon_message to mon.0 at 192.168.2.80:6789/0
-269> 2012-12-08 13:28:35.351789 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.80:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7eb06f0040 con 0x7f7eb0686b40
-268> 2012-12-08 13:28:35.351816 7f7ebdffb700 10 monclient: renew_subs
-267> 2012-12-08 13:28:35.352118 7f7e79676700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb0681cc0 sd=16 :59253 pgs=1679 cs=1 l=1).reader couldn't read tag, Success
-266> 2012-12-08 13:28:35.352207 7f7e79676700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb0681cc0 sd=16 :59253 pgs=1679 cs=1 l=1).fault 0: Success
-265> 2012-12-08 13:28:35.352549 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== osd.3 192.168.2.81:6804/3296 164 ==== osd_op_reply(737 1000004acc4.000000fb [delete] ondisk = 0) v4 ==== 119+0+0 (2680622697 0 0) 0x7f7e900080c0 con 0x7f7eb002d140
-264> 2012-12-08 13:28:35.352619 7f7ebdffb700 5 mds.0.73 is_laggy 33.750335 > 15 since last acked beacon
-263> 2012-12-08 13:28:35.352648 7f7ebdffb700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-262> 2012-12-08 13:28:35.352711 7f7ebdffb700 10 monclient: _reopen_session
-261> 2012-12-08 13:28:35.352720 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb0686b40 -- 0x7f7eb0603b90
-260> 2012-12-08 13:28:35.352892 7f7ebdffb700 10 monclient: _pick_new_mon picked mon.1 con 0x7f7eb0617300 addr 192.168.2.81:6789/0
-259> 2012-12-08 13:28:35.352969 7f7ebdffb700 10 monclient: _send_mon_message to mon.1 at 192.168.2.81:6789/0
-258> 2012-12-08 13:28:35.352986 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.81:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7eb06186c0 con 0x7f7eb0617300
-257> 2012-12-08 13:28:35.353051 7f7ebdffb700 10 monclient: renew_subs
-256> 2012-12-08 13:28:35.353102 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== osd.5 192.168.2.82:6804/20503 126 ==== osd_op_reply(734 1000004acc5.000000f8 [delete] ondisk = 0) v4 ==== 119+0+0 (3435548799 0 0) 0x228cdf0 con 0x7f7eb0047b40
-255> 2012-12-08 13:28:35.353236 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.80:6804/3448 -- osd_op(mds.0.73:748 1000004acc5.00000100 [delete] 0.6d9440f snapc 1=[]) v4 -- ?+0 0x7f7eb2ba1120 con 0x7f7eb0046250
-254> 2012-12-08 13:28:35.353459 7f7ebdffb700 5 mds.0.73 is_laggy 33.751175 > 15 since last acked beacon
-253> 2012-12-08 13:28:35.353496 7f7ebdffb700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-252> 2012-12-08 13:28:35.353503 7f7ebdffb700 10 monclient: _reopen_session
-251> 2012-12-08 13:28:35.353510 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb0617300 -- 0x7f7eb1e2b0e0
-250> 2012-12-08 13:28:35.353603 7f7ebdffb700 10 monclient: _pick_new_mon picked mon.0 con 0x7f7eb06ad210 addr 192.168.2.80:6789/0
-249> 2012-12-08 13:28:35.353635 7f7ebdffb700 10 monclient: _send_mon_message to mon.0 at 192.168.2.80:6789/0
-248> 2012-12-08 13:28:35.353647 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.80:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7eb0647690 con 0x7f7eb06ad210
-247> 2012-12-08 13:28:35.353668 7f7ebdffb700 10 monclient: renew_subs
-246> 2012-12-08 13:28:35.353986 7f7e79878700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb0603b90 sd=24 :51890 pgs=0 cs=0 l=1).connect couldn't write my addr, Interrupted system call
-245> 2012-12-08 13:28:35.354085 7f7e79878700 3 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb0603b90 sd=24 :51890 pgs=0 cs=0 l=1).connect fault, but state = closed != connecting, stopping
-244> 2012-12-08 13:28:35.355220 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== osd.5 192.168.2.82:6804/20503 127 ==== osd_op_reply(743 1000004acc5.000000fc [delete] ondisk = 0) v4 ==== 119+0+0 (3933303143 0 0) 0x228cdf0 con 0x7f7eb0047b40
-243> 2012-12-08 13:28:35.355375 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.82:6801/20404 -- osd_op(mds.0.73:749 1000004acc5.00000101 [delete] 0.4b301df snapc 1=[]) v4 -- ?+0 0x7f7eb06b3960 con 0x7f7eb002df80
-242> 2012-12-08 13:28:35.355431 7f7ebdffb700 5 mds.0.73 is_laggy 33.753146 > 15 since last acked beacon
-241> 2012-12-08 13:28:35.355466 7f7ebdffb700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-240> 2012-12-08 13:28:35.355472 7f7ebdffb700 10 monclient: _reopen_session
-239> 2012-12-08 13:28:35.355481 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb06ad210 -- 0x7f7eb067cd80
-238> 2012-12-08 13:28:35.355647 7f7eb92d8700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb067cd80 sd=16 :0 pgs=0 cs=0 l=1).connect couldn't write my banner, Interrupted system call
-237> 2012-12-08 13:28:35.356125 7f7eb92d8700 3 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb067cd80 sd=16 :0 pgs=0 cs=0 l=1).connect fault, but state = closed != connecting, stopping
-236> 2012-12-08 13:28:35.355953 7f7ebdffb700 10 monclient: _pick_new_mon picked mon.1 con 0x7f7eb0686b40 addr 192.168.2.81:6789/0
-235> 2012-12-08 13:28:35.356208 7f7ebdffb700 10 monclient: _send_mon_message to mon.1 at 192.168.2.81:6789/0
-234> 2012-12-08 13:28:35.356221 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.81:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7eb06186c0 con 0x7f7eb0686b40
-233> 2012-12-08 13:28:35.356345 7f7ebdffb700 10 monclient: renew_subs
-232> 2012-12-08 13:28:35.358151 7f7e79676700 10 mds.0.73 MDS::ms_get_authorizer type=mon
-231> 2012-12-08 13:28:35.358909 7f7ebdffb700 0 mds.0.73 ms_handle_connect on 192.168.2.81:6789/0
-230> 2012-12-08 13:28:35.360296 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== mon.1 192.168.2.81:6789/0 1 ==== auth_reply(proto 1 0 Success) v1 ==== 24+0+0 (1196077047 0 0) 0x7f7e94001450 con 0x7f7eb0686b40
-229> 2012-12-08 13:28:35.360424 7f7ebdffb700 10 monclient: _send_mon_message to mon.1 at 192.168.2.81:6789/0
-228> 2012-12-08 13:28:35.360627 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.81:6789/0 -- mon_subscribe({mdsmap=3921+,monmap=2+}) v2 -- ?+0 0x7f7eb0617300 con 0x7f7eb0686b40
-227> 2012-12-08 13:28:35.360681 7f7ebdffb700 10 monclient: _check_auth_rotating renewing rotating keys (they expired before 2012-12-08 13:28:05.360679)
-226> 2012-12-08 13:28:35.362850 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== mon.1 192.168.2.81:6789/0 2 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0 (2675486518 0 0) 0x7f7e94001210 con 0x7f7eb0686b40
-225> 2012-12-08 13:28:35.362910 7f7ebdffb700 10 monclient: handle_subscribe_ack sent 2012-12-08 13:28:35.351821 renew after 2012-12-08 13:31:05.351821
-224> 2012-12-08 13:28:35.394141 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== osd.4 192.168.2.82:6801/20404 150 ==== osd_op_reply(749 1000004acc5.00000101 [delete] ondisk = -108 (Cannot send after transport endpoint shutdown)) v4 ==== 119+0+0 (215636246 0 0) 0x7f7e840013d0 con 0x7f7eb002df80
-223> 2012-12-08 13:28:35.394313 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.82:6801/20404 -- osd_op(mds.0.73:750 1000004acc5.00000102 [delete] 0.5205ce7f snapc 1=[]) v4 -- ?+0 0x7f7eb06f09c0 con 0x7f7eb002df80
-222> 2012-12-08 13:28:35.394366 7f7ebdffb700 5 mds.0.73 is_laggy 33.792082 > 15 since last acked beacon
-221> 2012-12-08 13:28:35.394404 7f7ebdffb700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-220> 2012-12-08 13:28:35.394410 7f7ebdffb700 10 monclient: _reopen_session
-219> 2012-12-08 13:28:35.394418 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb0686b40 -- 0x7f7eb0616260
-218> 2012-12-08 13:28:35.394578 7f7ebdffb700 10 monclient: _pick_new_mon picked mon.0 con 0x7f7eb06b8f00 addr 192.168.2.80:6789/0
-217> 2012-12-08 13:28:35.394610 7f7ebdffb700 10 monclient: _send_mon_message to mon.0 at 192.168.2.80:6789/0
-216> 2012-12-08 13:28:35.394621 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.80:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7eb067fe70 con 0x7f7eb06b8f00
-215> 2012-12-08 13:28:35.394655 7f7ebdffb700 10 monclient: renew_subs
-214> 2012-12-08 13:28:35.394694 7f7eb92d8700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb0616260 sd=16 :59256 pgs=1680 cs=1 l=1).reader couldn't read tag, Success
-213> 2012-12-08 13:28:35.394728 7f7eb92d8700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb0616260 sd=16 :59256 pgs=1680 cs=1 l=1).fault 0: Success
-212> 2012-12-08 13:28:35.395912 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== osd.4 192.168.2.82:6801/20404 151 ==== osd_op_reply(750 1000004acc5.00000102 [delete] ondisk = -108 (Cannot send after transport endpoint shutdown)) v4 ==== 119+0+0 (3613621724 0 0) 0x7f7e840013d0 con 0x7f7eb002df80
-211> 2012-12-08 13:28:35.396123 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.82:6801/20404 -- osd_op(mds.0.73:751 1000004acc5.00000103 [delete] 0.d0152fbe snapc 1=[]) v4 -- ?+0 0x7f7eb06f09c0 con 0x7f7eb002df80
-210> 2012-12-08 13:28:35.396186 7f7ebdffb700 5 mds.0.73 is_laggy 33.793902 > 15 since last acked beacon
-209> 2012-12-08 13:28:35.396221 7f7ebdffb700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-208> 2012-12-08 13:28:35.396228 7f7ebdffb700 10 monclient: _reopen_session
-207> 2012-12-08 13:28:35.396235 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb06b8f00 -- 0x7f7eb068faa0
-206> 2012-12-08 13:28:35.396553 7f7ebdffb700 10 monclient: _pick_new_mon picked mon.1 con 0x7f7eb05f5c30 addr 192.168.2.81:6789/0
-205> 2012-12-08 13:28:35.396612 7f7ebdffb700 10 monclient: _send_mon_message to mon.1 at 192.168.2.81:6789/0
-204> 2012-12-08 13:28:35.396628 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.81:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7eb06f09c0 con 0x7f7eb05f5c30
-203> 2012-12-08 13:28:35.396651 7f7ebdffb700 10 monclient: renew_subs
-202> 2012-12-08 13:28:35.396719 7f7e79878700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb068faa0 sd=16 :51893 pgs=0 cs=0 l=1).connect couldn't write my addr, Interrupted system call
-201> 2012-12-08 13:28:35.396789 7f7e79878700 3 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb068faa0 sd=16 :51893 pgs=0 cs=0 l=1).connect fault, but state = closed != connecting, stopping
-200> 2012-12-08 13:28:35.397518 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== osd.4 192.168.2.82:6801/20404 152 ==== osd_op_reply(751 1000004acc5.00000103 [delete] ondisk = -108 (Cannot send after transport endpoint shutdown)) v4 ==== 119+0+0 (495899612 0 0) 0x7f7e840013d0 con 0x7f7eb002df80
-199> 2012-12-08 13:28:35.397772 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.82:6804/20503 -- osd_op(mds.0.73:752 1000004acc5.00000104 [delete] 0.15a07e9b snapc 1=[]) v4 -- ?+0 0x7f7eb0603b90 con 0x7f7eb0047b40
-198> 2012-12-08 13:28:35.397838 7f7ebdffb700 5 mds.0.73 is_laggy 33.795554 > 15 since last acked beacon
-197> 2012-12-08 13:28:35.397884 7f7ebdffb700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-196> 2012-12-08 13:28:35.397892 7f7ebdffb700 10 monclient: _reopen_session
-195> 2012-12-08 13:28:35.397900 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb05f5c30 -- 0x7f7eb0602b70
-194> 2012-12-08 13:28:35.398056 7f7eb92d8700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb0602b70 sd=16 :0 pgs=0 cs=0 l=1).connect couldn't read banner, Success
-193> 2012-12-08 13:28:35.398152 7f7eb92d8700 3 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb0602b70 sd=16 :0 pgs=0 cs=0 l=1).connect fault, but state = closed != connecting, stopping
-192> 2012-12-08 13:28:35.398198 7f7ebdffb700 10 monclient: _pick_new_mon picked mon.0 con 0x7f7eb0616330 addr 192.168.2.80:6789/0
-191> 2012-12-08 13:28:35.398259 7f7ebdffb700 10 monclient: _send_mon_message to mon.0 at 192.168.2.80:6789/0
-190> 2012-12-08 13:28:35.398282 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.80:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7eb0603b90 con 0x7f7eb0616330
-189> 2012-12-08 13:28:35.398319 7f7ebdffb700 10 monclient: renew_subs
-188> 2012-12-08 13:28:35.399053 7f7e79878700 10 mds.0.73 MDS::ms_get_authorizer type=mon
-187> 2012-12-08 13:28:35.399481 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== osd.5 192.168.2.82:6804/20503 128 ==== osd_op_reply(752 1000004acc5.00000104 [delete] ondisk = -108 (Cannot send after transport endpoint shutdown)) v4 ==== 119+0+0 (3095620367 0 0) 0x228cdf0 con 0x7f7eb0047b40
-186> 2012-12-08 13:28:35.399663 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.80:6801/3213 -- osd_op(mds.0.73:753 1000004acc5.00000105 [delete] 0.ce5819c6 snapc 1=[]) v4 -- ?+0 0x7f7eb06f09c0 con 0x7f7eb002c5b0
-185> 2012-12-08 13:28:35.399733 7f7ebdffb700 5 mds.0.73 is_laggy 33.797449 > 15 since last acked beacon
-184> 2012-12-08 13:28:35.399767 7f7ebdffb700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-183> 2012-12-08 13:28:35.399774 7f7ebdffb700 10 monclient: _reopen_session
-182> 2012-12-08 13:28:35.399783 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb0616330 -- 0x7f7eb068faa0
-181> 2012-12-08 13:28:35.399937 7f7ebdffb700 10 monclient: _pick_new_mon picked mon.1 con 0x7f7eb1dcb910 addr 192.168.2.81:6789/0
-180> 2012-12-08 13:28:35.399979 7f7ebdffb700 10 monclient: _send_mon_message to mon.1 at 192.168.2.81:6789/0
-179> 2012-12-08 13:28:35.399992 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.81:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7eb06d8050 con 0x7f7eb1dcb910
-178> 2012-12-08 13:28:35.400041 7f7ebdffb700 10 monclient: renew_subs
-177> 2012-12-08 13:28:35.400066 7f7ebdffb700 0 mds.0.73 ms_handle_connect on 192.168.2.80:6789/0
-176> 2012-12-08 13:28:35.400124 7f7e79878700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb068faa0 sd=24 :51895 pgs=636 cs=1 l=1).writer error sending 0x7f7eb0603b90, 4: Interrupted system call
-175> 2012-12-08 13:28:35.400204 7f7e79878700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb068faa0 sd=24 :51895 pgs=636 cs=1 l=1).fault 4: Interrupted system call
-174> 2012-12-08 13:28:35.402105 7f7e79676700 10 mds.0.73 MDS::ms_get_authorizer type=mon
-173> 2012-12-08 13:28:35.402730 7f7ebdffb700 0 mds.0.73 ms_handle_connect on 192.168.2.81:6789/0
-172> 2012-12-08 13:28:35.404133 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== mon.1 192.168.2.81:6789/0 1 ==== auth_reply(proto 1 0 Success) v1 ==== 24+0+0 (1196077047 0 0) 0x7f7e88002930 con 0x7f7eb1dcb910
-171> 2012-12-08 13:28:35.404212 7f7ebdffb700 10 monclient: _send_mon_message to mon.1 at 192.168.2.81:6789/0
-170> 2012-12-08 13:28:35.404247 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.81:6789/0 -- mon_subscribe({mdsmap=3921+,monmap=2+}) v2 -- ?+0 0x7f7eb066a340 con 0x7f7eb1dcb910
-169> 2012-12-08 13:28:35.404299 7f7ebdffb700 10 monclient: _check_auth_rotating renewing rotating keys (they expired before 2012-12-08 13:28:05.404297)
-168> 2012-12-08 13:28:35.405421 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== mon.1 192.168.2.81:6789/0 2 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0 (2675486518 0 0) 0x7f7e88002930 con 0x7f7eb1dcb910
-167> 2012-12-08 13:28:35.405510 7f7ebdffb700 10 monclient: handle_subscribe_ack sent 2012-12-08 13:28:35.394658 renew after 2012-12-08 13:31:05.394658
-166> 2012-12-08 13:28:35.445681 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== osd.2 192.168.2.81:6801/3201 87 ==== osd_op_reply(741 1000004acc5.000000fb [delete] ondisk = 0) v4 ==== 119+0+0 (1820713319 0 0) 0x7f7e840013d0 con 0x7f7e7c0039a0
-165> 2012-12-08 13:28:35.445832 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.82:6801/20404 -- osd_op(mds.0.73:754 1000004acc5.00000106 [delete] 0.f6b7a33b snapc 1=[]) v4 -- ?+0 0x7f7eb068faa0 con 0x7f7eb002df80
-164> 2012-12-08 13:28:35.445878 7f7ebdffb700 5 mds.0.73 is_laggy 33.843594 > 15 since last acked beacon
-163> 2012-12-08 13:28:35.445907 7f7ebdffb700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-162> 2012-12-08 13:28:35.445912 7f7ebdffb700 10 monclient: _reopen_session
-161> 2012-12-08 13:28:35.445919 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb1dcb910 -- 0x7f7eb061c370
-160> 2012-12-08 13:28:35.446101 7f7ebdffb700 10 monclient: _pick_new_mon picked mon.0 con 0x7f7eb05fe280 addr 192.168.2.80:6789/0
-159> 2012-12-08 13:28:35.446152 7f7ebdffb700 10 monclient: _send_mon_message to mon.0 at 192.168.2.80:6789/0
-158> 2012-12-08 13:28:35.446165 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.80:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7eb06b8b40 con 0x7f7eb05fe280
-157> 2012-12-08 13:28:35.446188 7f7ebdffb700 10 monclient: renew_subs
-156> 2012-12-08 13:28:35.446516 7f7eb92d8700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb061c370 sd=16 :59260 pgs=1681 cs=1 l=1).reader couldn't read tag, Success
-155> 2012-12-08 13:28:35.446623 7f7eb92d8700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb061c370 sd=16 :59260 pgs=1681 cs=1 l=1).fault 0: Success
-154> 2012-12-08 13:28:35.447589 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== osd.4 192.168.2.82:6801/20404 153 ==== osd_op_reply(754 1000004acc5.00000106 [delete] ondisk = -108 (Cannot send after transport endpoint shutdown)) v4 ==== 119+0+0 (4137632053 0 0) 0x7f7e840013d0 con 0x7f7eb002df80
-153> 2012-12-08 13:28:35.447774 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.81:6804/3296 -- osd_op(mds.0.73:755 1000004acc5.00000107 [delete] 0.270e1ad1 snapc 1=[]) v4 -- ?+0 0x7f7eb068faa0 con 0x7f7eb002d140
-152> 2012-12-08 13:28:35.447829 7f7ebdffb700 5 mds.0.73 is_laggy 33.845545 > 15 since last acked beacon
-151> 2012-12-08 13:28:35.447863 7f7ebdffb700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-150> 2012-12-08 13:28:35.447869 7f7ebdffb700 10 monclient: _reopen_session
-149> 2012-12-08 13:28:35.447877 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb05fe280 -- 0x7f7eb05fd9b0
-148> 2012-12-08 13:28:35.448720 7f7e79878700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb05fd9b0 sd=16 :0 pgs=0 cs=0 l=1).connect error 192.168.2.80:6789/0, 103: Software caused connection abort
-147> 2012-12-08 13:28:35.448845 7f7e79878700 3 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb05fd9b0 sd=16 :0 pgs=0 cs=0 l=1).connect fault, but state = closed != connecting, stopping
-146> 2012-12-08 13:28:35.448901 7f7ebdffb700 10 monclient: _pick_new_mon picked mon.1 con 0x7f7eb1dcb910 addr 192.168.2.81:6789/0
-145> 2012-12-08 13:28:35.449030 7f7ebdffb700 10 monclient: _send_mon_message to mon.1 at 192.168.2.81:6789/0
-144> 2012-12-08 13:28:35.449059 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.81:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7eb06b8b40 con 0x7f7eb1dcb910
-143> 2012-12-08 13:28:35.449244 7f7ebdffb700 10 monclient: renew_subs
-142> 2012-12-08 13:28:35.449284 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== osd.4 192.168.2.82:6801/20404 154 ==== osd_op_reply(731 1000004acc5.000000f5 [delete] ondisk = 0) v4 ==== 119+0+0 (3162995678 0 0) 0x7f7e840017d0 con 0x7f7eb002df80
-141> 2012-12-08 13:28:35.449407 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.80:6801/3213 -- osd_op(mds.0.73:756 1000004acc5.00000108 [delete] 0.5dc10381 snapc 1=[]) v4 -- ?+0 0x7f7eb06747c0 con 0x7f7eb002c5b0
-140> 2012-12-08 13:28:35.449465 7f7ebdffb700 5 mds.0.73 is_laggy 33.847181 > 15 since last acked beacon
-139> 2012-12-08 13:28:35.449508 7f7ebdffb700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-138> 2012-12-08 13:28:35.449515 7f7ebdffb700 10 monclient: _reopen_session
-137> 2012-12-08 13:28:35.449522 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb1dcb910 -- 0x7f7eb068faa0
-136> 2012-12-08 13:28:35.449736 7f7ebdffb700 10 monclient: _pick_new_mon picked mon.0 con 0x7f7eb05fda80 addr 192.168.2.80:6789/0
-135> 2012-12-08 13:28:35.449773 7f7ebdffb700 10 monclient: _send_mon_message to mon.0 at 192.168.2.80:6789/0
-134> 2012-12-08 13:28:35.449785 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.80:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7eb06873e0 con 0x7f7eb05fda80
-133> 2012-12-08 13:28:35.450152 7f7ebdffb700 10 monclient: renew_subs
-132> 2012-12-08 13:28:35.449815 7f7eb92d8700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb068faa0 sd=16 :0 pgs=0 cs=0 l=1).connect error 192.168.2.81:6789/0, 104: Connection reset by peer
-131> 2012-12-08 13:28:35.450184 7f7eb92d8700 3 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb068faa0 sd=16 :0 pgs=0 cs=0 l=1).connect fault, but state = closed != connecting, stopping
-130> 2012-12-08 13:28:35.450987 7f7e79878700 10 mds.0.73 MDS::ms_get_authorizer type=mon
-129> 2012-12-08 13:28:35.487925 7f7ebdffb700 0 mds.0.73 ms_handle_connect on 192.168.2.80:6789/0
-128> 2012-12-08 13:28:35.827401 7f7ebbff7700 5 mds.0.73 is_laggy 34.225117 > 15 since last acked beacon
-127> 2012-12-08 13:28:35.827475 7f7ebbff7700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-126> 2012-12-08 13:28:35.827483 7f7ebbff7700 10 monclient: _reopen_session
-125> 2012-12-08 13:28:35.827492 7f7ebbff7700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb05fda80 -- 0x7f7eb06747c0
-124> 2012-12-08 13:28:35.828145 7f7ebbff7700 10 monclient: _pick_new_mon picked mon.2 con 0x7f7e9c0d58d0 addr 192.168.2.82:6789/0
-123> 2012-12-08 13:28:35.828192 7f7ebbff7700 10 monclient: _send_mon_message to mon.2 at 192.168.2.82:6789/0
-122> 2012-12-08 13:28:35.828201 7f7ebbff7700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.82:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7e9c043900 con 0x7f7e9c0d58d0
-121> 2012-12-08 13:28:35.828221 7f7ebbff7700 10 monclient: renew_subs
-120> 2012-12-08 13:28:35.828229 7f7ebbff7700 5 mds.0.73 tick bailing out since we seem laggy
-119> 2012-12-08 13:28:35.828211 7f7eb92d8700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb06747c0 sd=24 :51899 pgs=637 cs=1 l=1).reader couldn't read tag, Success
-118> 2012-12-08 13:28:35.828292 7f7eb92d8700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb06747c0 sd=24 :51899 pgs=637 cs=1 l=1).fault 0: Success
-117> 2012-12-08 13:28:35.829814 7f7e79676700 10 mds.0.73 MDS::ms_get_authorizer type=mon
-116> 2012-12-08 13:28:35.830301 7f7ebdffb700 0 mds.0.73 ms_handle_connect on 192.168.2.82:6789/0
-115> 2012-12-08 13:28:35.831817 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== mon.2 192.168.2.82:6789/0 1 ==== auth_reply(proto 1 0 Success) v1 ==== 24+0+0 (1196077047 0 0) 0x7f7e88002b00 con 0x7f7e9c0d58d0
-114> 2012-12-08 13:28:35.831908 7f7ebdffb700 10 monclient: _send_mon_message to mon.2 at 192.168.2.82:6789/0
-113> 2012-12-08 13:28:35.831924 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.82:6789/0 -- mon_subscribe({mdsmap=3921+,monmap=2+}) v2 -- ?+0 0x7f7e9c12b910 con 0x7f7e9c0d58d0
-112> 2012-12-08 13:28:35.832045 7f7ebdffb700 10 monclient: _check_auth_rotating renewing rotating keys (they expired before 2012-12-08 13:28:05.832042)
-111> 2012-12-08 13:28:35.833152 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== mon.2 192.168.2.82:6789/0 2 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0 (2675486518 0 0) 0x7f7e88002b00 con 0x7f7e9c0d58d0
-110> 2012-12-08 13:28:35.833188 7f7ebdffb700 10 monclient: handle_subscribe_ack sent 2012-12-08 13:28:35.446193 renew after 2012-12-08 13:31:05.446193
-109> 2012-12-08 13:28:35.850423 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== osd.2 192.168.2.81:6801/3201 88 ==== osd_op_reply(746 1000004acc4.000000fd [delete] ondisk = 0) v4 ==== 119+0+0 (714955370 0 0) 0x7f7e840017d0 con 0x7f7e7c0039a0
-108> 2012-12-08 13:28:35.850545 7f7ebdffb700 5 mds.0.73 is_laggy 34.248261 > 15 since last acked beacon
-107> 2012-12-08 13:28:35.850592 7f7ebdffb700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-106> 2012-12-08 13:28:35.850600 7f7ebdffb700 10 monclient: _reopen_session
-105> 2012-12-08 13:28:35.850610 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7e9c0d58d0 -- 0x7f7e9c0d5690
-104> 2012-12-08 13:28:35.850791 7f7ebdffb700 10 monclient: _pick_new_mon picked mon.0 con 0x7f7eb06b8c10 addr 192.168.2.80:6789/0
-103> 2012-12-08 13:28:35.850871 7f7ebdffb700 10 monclient: _send_mon_message to mon.0 at 192.168.2.80:6789/0
-102> 2012-12-08 13:28:35.850900 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.80:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7eb0665aa0 con 0x7f7eb06b8c10
-101> 2012-12-08 13:28:35.850941 7f7ebdffb700 10 monclient: renew_subs
-100> 2012-12-08 13:28:35.851104 7f7eb92d8700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.82:6789/0 pipe(0x7f7e9c0d5690 sd=16 :43695 pgs=2136 cs=1 l=1).reader couldn't read tag, Success
-99> 2012-12-08 13:28:35.851159 7f7eb92d8700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.82:6789/0 pipe(0x7f7e9c0d5690 sd=16 :43695 pgs=2136 cs=1 l=1).fault 0: Success
-98> 2012-12-08 13:28:35.851730 7f7e79878700 10 mds.0.73 MDS::ms_get_authorizer type=mon
-97> 2012-12-08 13:28:35.852089 7f7ebdffb700 0 mds.0.73 ms_handle_connect on 192.168.2.80:6789/0
-96> 2012-12-08 13:28:36.051157 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== osd.0 192.168.2.80:6801/3213 113 ==== osd_op_reply(730 1000004acc4.000000f8 [delete] ondisk = 0) v4 ==== 119+0+0 (1917671650 0 0) 0x7f7e88003000 con 0x7f7eb002c5b0
-95> 2012-12-08 13:28:36.051283 7f7ebdffb700 5 mds.0.73 is_laggy 34.448999 > 15 since last acked beacon
-94> 2012-12-08 13:28:36.051320 7f7ebdffb700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-93> 2012-12-08 13:28:36.051327 7f7ebdffb700 10 monclient: _reopen_session
-92> 2012-12-08 13:28:36.051336 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb06b8c10 -- 0x7f7eb05fc520
-91> 2012-12-08 13:28:36.053621 7f7ebdffb700 10 monclient: _pick_new_mon picked mon.1 con 0x7f7eb06b4160 addr 192.168.2.81:6789/0
-90> 2012-12-08 13:28:36.053920 7f7ebdffb700 10 monclient: _send_mon_message to mon.1 at 192.168.2.81:6789/0
-89> 2012-12-08 13:28:36.053944 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.81:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7eb06b42b0 con 0x7f7eb06b4160
-88> 2012-12-08 13:28:36.054132 7f7ebdffb700 10 monclient: renew_subs
-87> 2012-12-08 13:28:36.054166 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== osd.0 192.168.2.80:6801/3213 114 ==== osd_op_reply(733 1000004acc5.000000f7 [delete] ondisk = 0) v4 ==== 119+0+0 (1536040717 0 0) 0x7f7e88003360 con 0x7f7eb002c5b0
-86> 2012-12-08 13:28:36.054288 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.80:6804/3448 -- osd_op(mds.0.73:757 1000004acc5.00000109 [delete] 0.2da2cf22 snapc 1=[]) v4 -- ?+0 0x7f7eb0613dc0 con 0x7f7eb0046250
-85> 2012-12-08 13:28:36.054342 7f7ebdffb700 5 mds.0.73 is_laggy 34.452058 > 15 since last acked beacon
-84> 2012-12-08 13:28:36.054377 7f7ebdffb700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-83> 2012-12-08 13:28:36.054384 7f7ebdffb700 10 monclient: _reopen_session
-82> 2012-12-08 13:28:36.054391 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb06b4160 -- 0x7f7eb06181f0
-81> 2012-12-08 13:28:36.054560 7f7ebdffb700 10 monclient: _pick_new_mon picked mon.0 con 0x7f7eb0668680 addr 192.168.2.80:6789/0
-80> 2012-12-08 13:28:36.054592 7f7ebdffb700 10 monclient: _send_mon_message to mon.0 at 192.168.2.80:6789/0
-79> 2012-12-08 13:28:36.054637 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.80:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7eb0690060 con 0x7f7eb0668680
-78> 2012-12-08 13:28:36.054664 7f7ebdffb700 10 monclient: renew_subs
-77> 2012-12-08 13:28:36.056083 7f7eb92d8700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb05fc520 sd=24 :51901 pgs=638 cs=1 l=1).reader couldn't read tag, Success
-76> 2012-12-08 13:28:36.056291 7f7eb92d8700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb05fc520 sd=24 :51901 pgs=638 cs=1 l=1).fault 0: Success
-75> 2012-12-08 13:28:36.058216 7f7eb93d9700 10 mds.0.73 MDS::ms_get_authorizer type=mon
-74> 2012-12-08 13:28:36.061096 7f7ebdffb700 0 mds.0.73 ms_handle_connect on 192.168.2.80:6789/0
-73> 2012-12-08 13:28:36.449276 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== osd.3 192.168.2.81:6804/3296 165 ==== osd_op_reply(755 1000004acc5.00000107 [delete] ondisk = -108 (Cannot send after transport endpoint shutdown)) v4 ==== 119+0+0 (1167422262 0 0) 0x7f7e900080c0 con 0x7f7eb002d140
-72> 2012-12-08 13:28:36.449447 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.81:6804/3296 -- osd_op(mds.0.73:758 1000004acc5.0000010a [delete] 0.cb258d43 snapc 1=[]) v4 -- ?+0 0x7f7eb05fc520 con 0x7f7eb002d140
-71> 2012-12-08 13:28:36.449501 7f7ebdffb700 5 mds.0.73 is_laggy 34.847217 > 15 since last acked beacon
-70> 2012-12-08 13:28:36.449543 7f7ebdffb700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-69> 2012-12-08 13:28:36.449549 7f7ebdffb700 10 monclient: _reopen_session
-68> 2012-12-08 13:28:36.449557 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb0668680 -- 0x7f7eb0668440
-67> 2012-12-08 13:28:36.449740 7f7ebdffb700 10 monclient: _pick_new_mon picked mon.2 con 0x7f7eb067edd0 addr 192.168.2.82:6789/0
-66> 2012-12-08 13:28:36.449777 7f7ebdffb700 10 monclient: _send_mon_message to mon.2 at 192.168.2.82:6789/0
-65> 2012-12-08 13:28:36.449802 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.82:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7eb05fc520 con 0x7f7eb067edd0
-64> 2012-12-08 13:28:36.449844 7f7ebdffb700 10 monclient: renew_subs
-63> 2012-12-08 13:28:36.450088 7f7eb92d8700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb0668440 sd=16 :51902 pgs=639 cs=1 l=1).reader couldn't read tag, Success
-62> 2012-12-08 13:28:36.450142 7f7eb92d8700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb0668440 sd=16 :51902 pgs=639 cs=1 l=1).fault 0: Success
-61> 2012-12-08 13:28:36.450987 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== osd.3 192.168.2.81:6804/3296 166 ==== osd_op_reply(758 1000004acc5.0000010a [delete] ondisk = -108 (Cannot send after transport endpoint shutdown)) v4 ==== 119+0+0 (3714997822 0 0) 0x7f7e900080c0 con 0x7f7eb002d140
-60> 2012-12-08 13:28:36.451209 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.80:6804/3448 -- osd_op(mds.0.73:759 1000004acc5.0000010b [delete] 0.7380b906 snapc 1=[]) v4 -- ?+0 0x7f7eb06b4160 con 0x7f7eb0046250
-59> 2012-12-08 13:28:36.451266 7f7ebdffb700 5 mds.0.73 is_laggy 34.848982 > 15 since last acked beacon
-58> 2012-12-08 13:28:36.451301 7f7ebdffb700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-57> 2012-12-08 13:28:36.451307 7f7ebdffb700 10 monclient: _reopen_session
-56> 2012-12-08 13:28:36.451314 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb067edd0 -- 0x7f7eb06181f0
-55> 2012-12-08 13:28:36.451496 7f7ebdffb700 10 monclient: _pick_new_mon picked mon.0 con 0x7f7eb06e25f0 addr 192.168.2.80:6789/0
-54> 2012-12-08 13:28:36.451451 7f7e79676700 1 -- 192.168.2.80:6800/11192 >> 192.168.2.82:6789/0 pipe(0x7f7eb06181f0 sd=24 :43698 pgs=0 cs=0 l=1).do_sendmsg error Broken pipe
-53> 2012-12-08 13:28:36.451584 7f7e79676700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.82:6789/0 pipe(0x7f7eb06181f0 sd=24 :43698 pgs=0 cs=0 l=1).connect couldn't write my addr, Broken pipe
-52> 2012-12-08 13:28:36.451611 7f7e79676700 3 -- 192.168.2.80:6800/11192 >> 192.168.2.82:6789/0 pipe(0x7f7eb06181f0 sd=24 :43698 pgs=0 cs=0 l=1).connect fault, but state = closed != connecting, stopping
-51> 2012-12-08 13:28:36.451569 7f7ebdffb700 10 monclient: _send_mon_message to mon.0 at 192.168.2.80:6789/0
-50> 2012-12-08 13:28:36.451665 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.80:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7eb068b6f0 con 0x7f7eb06e25f0
-49> 2012-12-08 13:28:36.451702 7f7ebdffb700 10 monclient: renew_subs
-48> 2012-12-08 13:28:36.452858 7f7eb92d8700 10 mds.0.73 MDS::ms_get_authorizer type=mon
-47> 2012-12-08 13:28:36.453275 7f7ebdffb700 0 mds.0.73 ms_handle_connect on 192.168.2.80:6789/0
-46> 2012-12-08 13:28:36.612959 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== osd.0 192.168.2.80:6801/3213 115 ==== osd_op_reply(742 1000004acd1.000003bc [stat] = -2 (No such file or directory)) v4 ==== 119+0+0 (1158833999 0 0) 0x7f7e88003c40 con 0x7f7eb002c5b0
-45> 2012-12-08 13:28:36.613187 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.82:6804/20503 -- osd_op(mds.0.73:760 1000004acd1.000003bb [stat] 0.cb422078 rwordered) v4 -- ?+0 0x7f7eb05fc520 con 0x7f7eb0047b40
-44> 2012-12-08 13:28:36.613239 7f7ebdffb700 5 mds.0.73 is_laggy 35.010955 > 15 since last acked beacon
-43> 2012-12-08 13:28:36.613269 7f7ebdffb700 5 mds.0.73 initiating monitor reconnect; maybe we're not the slow one
-42> 2012-12-08 13:28:36.613274 7f7ebdffb700 10 monclient: _reopen_session
-41> 2012-12-08 13:28:36.613281 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb06e25f0 -- 0x7f7eb067d650
-40> 2012-12-08 13:28:36.613584 7f7ebdffb700 10 monclient: _pick_new_mon picked mon.1 con 0x7f7eb068b6f0 addr 192.168.2.81:6789/0
-39> 2012-12-08 13:28:36.613636 7f7ebdffb700 10 monclient: _send_mon_message to mon.1 at 192.168.2.81:6789/0
-38> 2012-12-08 13:28:36.613649 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 --> 192.168.2.81:6789/0 -- auth(proto 0 30 bytes epoch 1) v1 -- ?+0 0x7f7eb31e1a10 con 0x7f7eb068b6f0
-37> 2012-12-08 13:28:36.613670 7f7ebdffb700 10 monclient: renew_subs
-36> 2012-12-08 13:28:36.613833 7f7e79676700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb067d650 sd=16 :51904 pgs=640 cs=1 l=1).reader couldn't read tag, Success
-35> 2012-12-08 13:28:36.613874 7f7e79676700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6789/0 pipe(0x7f7eb067d650 sd=16 :51904 pgs=640 cs=1 l=1).fault 0: Success
-34> 2012-12-08 13:28:36.615489 7f7eb93d9700 10 mds.0.73 MDS::ms_get_authorizer type=mon
-33> 2012-12-08 13:28:36.615447 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 <== osd.5 192.168.2.82:6804/20503 129 ==== osd_op_reply(760 1000004acd1.000003bb [stat] = -108 (Cannot send after transport endpoint shutdown)) v4 ==== 119+0+0 (3232376619 0 0) 0x228cdf0 con 0x7f7eb0047b40
-32> 2012-12-08 13:28:36.732864 7f7ebdffb700 10 mds.0.cache _recovered r=-108 size=1164705792 mtime=2012-12-08 13:23:10.556948 for [inode 1000004acd1 [2,head] ~mds0/stray1/1000004acd1 auth v46829 ap=1+0 recovering s=1164705792 nl=0 n(v0 b1164705792 1=1+0) (ifile scan) (iversion lock) cr={8370=0-4294967296@1} | dirty authpin 0x7f7e79f01dd0]
-31> 2012-12-08 13:28:36.732997 7f7ebdffb700 0 mds.0.cache recovery error! -108
-30> 2012-12-08 13:28:36.733030 7f7ebdffb700 1 mds.0.73 suicide. wanted down:dne, now up:active
-29> 2012-12-08 13:28:36.733046 7f7ebdffb700 7 mds.0.cache WARNING: mdcache shutdown with non-empty cache
-28> 2012-12-08 13:28:36.733053 7f7ebdffb700 15 mds.0.cache show_subtrees
-27> 2012-12-08 13:28:36.733072 7f7ebdffb700 10 mds.0.cache |__ 0 auth [dir 100 ~mds0/ [2,head] auth v=66393 cv=0/0 dir_auth=0 ap=0+0+1 state=1610612738|complete f(v0 11=1+10) n(v279 rc2012-12-08 13:23:39.404704 b3523839488 16=4+12) hs=11+0,ss=0+0 dirty=2 | child subtree dirty 0x7f7e7c005728]
-26> 2012-12-08 13:28:36.733173 7f7ebdffb700 10 mds.0.cache |__ 0 auth [dir 1 / [2,head] auth v=123696 cv=123673/123673 dir_auth=0 state=1610612738|complete f(v41 m2012-12-07 15:19:24.674346 3=0+3) n(v8410 rc2012-12-08 13:23:39.404704 b760095324243 288190=266891+21299) hs=3+0,ss=0+0 dirty=1 | child subtree dirty 0x7f7e7c005330]
-25> 2012-12-08 13:28:36.763989 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb002c5b0 -- 0x7f7eb002c370
-24> 2012-12-08 13:28:36.764245 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb0046250 -- 0x7f7eb0046010
-23> 2012-12-08 13:28:36.764318 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7e7c0039a0 -- 0x7f7e7c003760
-22> 2012-12-08 13:28:36.764385 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb002d140 -- 0x7f7eb002cf00
-21> 2012-12-08 13:28:36.764434 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb002df80 -- 0x7f7eb002dd40
-20> 2012-12-08 13:28:36.764480 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down 0x7f7eb0047b40 -- 0x7f7eb0047900
-19> 2012-12-08 13:28:36.764527 7f7ebdffb700 1 -- 192.168.2.80:6800/11192 mark_down_all
-18> 2012-12-08 13:28:36.764539 7f7ebdffb700 5 -- 192.168.2.80:6800/11192 mark_down_all 192.168.2.131:0/25575830 0x7f7e7e7217b0
-17> 2012-12-08 13:28:36.764612 7f7ebb2f1700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6801/3213 pipe(0x7f7eb002c370 sd=17 :51120 pgs=211 cs=1 l=1).reader couldn't read tag, Success
-16> 2012-12-08 13:28:36.764651 7f7ebb2f1700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6801/3213 pipe(0x7f7eb002c370 sd=17 :51120 pgs=211 cs=1 l=1).fault 0: Success
-15> 2012-12-08 13:28:36.764805 7f7eba4ea700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6801/3201 pipe(0x7f7e7c003760 sd=22 :53748 pgs=249 cs=1 l=1).reader couldn't read tag, Success
-14> 2012-12-08 13:28:36.764826 7f7eba4ea700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6801/3201 pipe(0x7f7e7c003760 sd=22 :53748 pgs=249 cs=1 l=1).fault 0: Success
-13> 2012-12-08 13:28:36.764884 7f7ebb3f2700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6804/3296 pipe(0x7f7eb002cf00 sd=19 :33273 pgs=239 cs=1 l=1).reader couldn't read tag, Success
-12> 2012-12-08 13:28:36.764904 7f7ebb3f2700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6804/3296 pipe(0x7f7eb002cf00 sd=19 :33273 pgs=239 cs=1 l=1).fault 0: Success
-11> 2012-12-08 13:28:36.764982 7f7ebb4f3700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.82:6801/20404 pipe(0x7f7eb002dd40 sd=18 :34686 pgs=551 cs=1 l=1).reader couldn't read tag, Success
-10> 2012-12-08 13:28:36.765044 7f7ebb4f3700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.82:6801/20404 pipe(0x7f7eb002dd40 sd=18 :34686 pgs=551 cs=1 l=1).fault 0: Success
-9> 2012-12-08 13:28:36.765110 7f7ebaeed700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.82:6804/20503 pipe(0x7f7eb0047900 sd=21 :59698 pgs=578 cs=1 l=1).reader couldn't read tag, Success
-8> 2012-12-08 13:28:36.765130 7f7ebaeed700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.82:6804/20503 pipe(0x7f7eb0047900 sd=21 :59698 pgs=578 cs=1 l=1).fault 0: Success
-7> 2012-12-08 13:28:36.765178 7f7ebdffb700 5 -- 192.168.2.80:6800/11192 mark_down_all 192.168.2.81:6789/0 0x7f7eb06b4230
-6> 2012-12-08 13:28:36.765264 7f7e79676700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb06b4230 sd=16 :59269 pgs=1682 cs=1 l=1).reader couldn't read tag, Success
-5> 2012-12-08 13:28:36.765331 7f7e79676700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.81:6789/0 pipe(0x7f7eb06b4230 sd=16 :59269 pgs=1682 cs=1 l=1).fault 0: Success
-4> 2012-12-08 13:28:36.765393 7f7eba3e9700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.131:0/25575830 pipe(0x7f7e7e7217b0 sd=23 :6800 pgs=36 cs=1 l=0).reader couldn't read tag, Success
-3> 2012-12-08 13:28:36.765428 7f7eba3e9700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.131:0/25575830 pipe(0x7f7e7e7217b0 sd=23 :6800 pgs=36 cs=1 l=0).fault 0: Success
-2> 2012-12-08 13:28:36.765636 7f7ebafee700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6804/3448 pipe(0x7f7eb0046010 sd=20 :47669 pgs=281 cs=1 l=1).reader couldn't read tag, Success
-1> 2012-12-08 13:28:36.765659 7f7ebafee700 2 -- 192.168.2.80:6800/11192 >> 192.168.2.80:6804/3448 pipe(0x7f7eb0046010 sd=20 :47669 pgs=281 cs=1 l=1).fault 0: Success
0> 2012-12-08 13:28:37.702710 7f7ebdffb700 -1 mds/MDCache.cc: In function 'void MDCache::_recovered(CInode*, int, uint64_t, utime_t)' thread 7f7ebdffb700 time 2012-12-08 13:28:36.777853
mds/MDCache.cc: 5188: FAILED assert(0)

ceph version 0.55 (690f8175606edf37a3177c27a3949c78fd37099f)
1: (MDCache::_recovered(CInode*, int, unsigned long, utime_t)+0x109) [0x567f19]
2: (Filer::_probed(Filer::Probe*, object_t const&, unsigned long, utime_t)+0xb5a) [0x6eef9a]
3: (Objecter::C_Stat::finish(int)+0xc9) [0x6ef989]
4: (Objecter::handle_osd_op_reply(MOSDOpReply*)+0xe58) [0x6e06f8]
5: (MDS::handle_core_message(Message*)+0x957) [0x4bb577]
6: (MDS::_dispatch(Message*)+0x2f) [0x4bb62f]
7: (MDS::ms_dispatch(Message*)+0x19b) [0x4bd20b]
8: (DispatchQueue::entry()+0x309) [0x7c8de9]
9: (DispatchQueue::DispatchThread::entry()+0xd) [0x7c6a8d]
10: (()+0x7851) [0x7f7ec67c8851]
11: (clone()+0x6d) [0x7f7ec596a11d]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- logging levels ---
0/ 5 none
0/ 1 lockdep
0/ 1 context
1/ 1 crush
20/20 mds
1/ 5 mds_balancer
1/ 5 mds_locker
1/ 5 mds_log
1/ 5 mds_log_expire
1/ 5 mds_migrator
0/ 1 buffer
0/ 1 timer
0/ 1 filer
0/ 1 striper
0/ 1 objecter
0/ 5 rados
0/ 5 rbd
0/ 5 journaler
0/ 5 objectcacher
0/ 5 client
0/ 5 osd
0/ 5 optracker
0/ 5 objclass
1/ 3 filestore
1/ 3 journal
0/ 5 ms
1/ 5 mon
0/10 monc
0/ 5 paxos
0/ 5 tp
1/ 5 auth
1/ 5 crypto
1/ 1 finisher
1/ 5 heartbeatmap
1/ 5 perfcounter
1/ 5 rgw
1/ 5 hadoop
1/ 5 javaclient
1/ 5 asok
1/ 1 throttle
-2/-2 (syslog threshold)
-1/-1 (stderr threshold)
max_recent 100000
max_new 1000
log_file /var/log/ceph/mds.alpha.log
--- end dump of recent events ---
2012-12-08 13:28:44.023716 7f7ebdffb700 -1 *** Caught signal (Aborted) **
in thread 7f7ebdffb700

ceph version 0.55 (690f8175606edf37a3177c27a3949c78fd37099f)
1: /usr/bin/ceph-mds() [0x801a41]
2: (()+0xf500) [0x7f7ec67d0500]
3: (gsignal()+0x35) [0x7f7ec58b48a5]
4: (abort()+0x175) [0x7f7ec58b6085]
5: (__gnu_cxx::__verbose_terminate_handler()+0x12d) [0x7f7ec616da5d]
6: (()+0xbcbe6) [0x7f7ec616bbe6]
7: (()+0xbcc13) [0x7f7ec616bc13]
8: (()+0xbcd0e) [0x7f7ec616bd0e]
9: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x7f2) [0x77cd32]
10: (MDCache::_recovered(CInode*, int, unsigned long, utime_t)+0x109) [0x567f19]
11: (Filer::_probed(Filer::Probe*, object_t const&, unsigned long, utime_t)+0xb5a) [0x6eef9a]
12: (Objecter::C_Stat::finish(int)+0xc9) [0x6ef989]
13: (Objecter::handle_osd_op_reply(MOSDOpReply*)+0xe58) [0x6e06f8]
14: (MDS::handle_core_message(Message*)+0x957) [0x4bb577]
15: (MDS::_dispatch(Message*)+0x2f) [0x4bb62f]
16: (MDS::ms_dispatch(Message*)+0x19b) [0x4bd20b]
17: (DispatchQueue::entry()+0x309) [0x7c8de9]
18: (DispatchQueue::DispatchThread::entry()+0xd) [0x7c6a8d]
19: (()+0x7851) [0x7f7ec67c8851]
20: (clone()+0x6d) [0x7f7ec596a11d]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- begin dump of recent events ---
0> 2012-12-08 13:28:44.023716 7f7ebdffb700 -1 *** Caught signal (Aborted) **
in thread 7f7ebdffb700

ceph version 0.55 (690f8175606edf37a3177c27a3949c78fd37099f)
1: /usr/bin/ceph-mds() [0x801a41]
2: (()+0xf500) [0x7f7ec67d0500]
3: (gsignal()+0x35) [0x7f7ec58b48a5]
4: (abort()+0x175) [0x7f7ec58b6085]
5: (__gnu_cxx::__verbose_terminate_handler()+0x12d) [0x7f7ec616da5d]
6: (()+0xbcbe6) [0x7f7ec616bbe6]
7: (()+0xbcc13) [0x7f7ec616bc13]
8: (()+0xbcd0e) [0x7f7ec616bd0e]
9: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x7f2) [0x77cd32]
10: (MDCache::_recovered(CInode*, int, unsigned long, utime_t)+0x109) [0x567f19]
11: (Filer::_probed(Filer::Probe*, object_t const&, unsigned long, utime_t)+0xb5a) [0x6eef9a]
12: (Objecter::C_Stat::finish(int)+0xc9) [0x6ef989]
13: (Objecter::handle_osd_op_reply(MOSDOpReply*)+0xe58) [0x6e06f8]
14: (MDS::handle_core_message(Message*)+0x957) [0x4bb577]
15: (MDS::_dispatch(Message*)+0x2f) [0x4bb62f]
16: (MDS::ms_dispatch(Message*)+0x19b) [0x4bd20b]
17: (DispatchQueue::entry()+0x309) [0x7c8de9]
18: (DispatchQueue::DispatchThread::entry()+0xd) [0x7c6a8d]
19: (()+0x7851) [0x7f7ec67c8851]
20: (clone()+0x6d) [0x7f7ec596a11d]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- logging levels ---
0/ 5 none
0/ 1 lockdep
0/ 1 context
1/ 1 crush
20/20 mds
1/ 5 mds_balancer
1/ 5 mds_locker
1/ 5 mds_log
1/ 5 mds_log_expire
1/ 5 mds_migrator
0/ 1 buffer
0/ 1 timer
0/ 1 filer
0/ 1 striper
0/ 1 objecter
0/ 5 rados
0/ 5 rbd
0/ 5 journaler
0/ 5 objectcacher
0/ 5 client
0/ 5 osd
0/ 5 optracker
0/ 5 objclass
1/ 3 filestore
1/ 3 journal
0/ 5 ms
1/ 5 mon
0/10 monc
0/ 5 paxos
0/ 5 tp
1/ 5 auth
1/ 5 crypto
1/ 1 finisher
1/ 5 heartbeatmap
1/ 5 perfcounter
1/ 5 rgw
1/ 5 hadoop
1/ 5 javaclient
1/ 5 asok
1/ 1 throttle
-2/-2 (syslog threshold)
-1/-1 (stderr threshold)
max_recent 100000
max_new 1000
log_file /var/log/ceph/mds.alpha.log
--- end dump of recent events ---
(1-1/2)