Project

General

Profile

Support #16043 » mds.virt-master.log

Andrey Matyashov, 05/27/2016 09:43 AM

 
2016-05-27 12:40:29.292037 7f5e3d4a4180 0 set uid:gid to 64045:64045 (ceph:ceph)
2016-05-27 12:40:29.292049 7f5e3d4a4180 0 ceph version 10.2.1 (3a66dd4f30852819c1bdaa8ec23c795d4ad77269), process ceph-mds, pid 13844
2016-05-27 12:40:29.292790 7f5e3d4a4180 10 -- :/0 rank.bind 10.100.23.2:0/0
2016-05-27 12:40:29.292797 7f5e3d4a4180 10 accepter.accepter.bind
2016-05-27 12:40:29.292811 7f5e3d4a4180 10 accepter.accepter.bind bound on random port 10.100.23.2:6801/0
2016-05-27 12:40:29.292814 7f5e3d4a4180 10 accepter.accepter.bind bound to 10.100.23.2:6801/0
2016-05-27 12:40:29.292818 7f5e3d4a4180 1 -- 10.100.23.2:0/0 learned my addr 10.100.23.2:0/0
2016-05-27 12:40:29.292822 7f5e3d4a4180 1 accepter.accepter.bind my_inst.addr is 10.100.23.2:6801/13844 need_addr=0
2016-05-27 12:40:29.294670 7f5e3d4a4180 1 -- 10.100.23.2:6801/13844 messenger.start
2016-05-27 12:40:29.294738 7f5e37bbe700 10 -- 10.100.23.2:6801/13844 reaper_entry start
2016-05-27 12:40:29.294762 7f5e37bbe700 10 -- 10.100.23.2:6801/13844 reaper
2016-05-27 12:40:29.294765 7f5e37bbe700 10 -- 10.100.23.2:6801/13844 reaper done
2016-05-27 12:40:29.294923 7f5e3d4a4180 10 -- 10.100.23.2:6801/13844 ready 10.100.23.2:6801/13844
2016-05-27 12:40:29.294989 7f5e3d4a4180 1 accepter.accepter.start
2016-05-27 12:40:29.295079 7f5e35bba700 10 accepter.accepter starting
2016-05-27 12:40:29.295363 7f5e3d4a4180 10 -- 10.100.23.2:6801/13844 connect_rank to 10.100.23.4:6789/0, creating pipe and registering
2016-05-27 12:40:29.295412 7f5e3d4a4180 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=-1 :0 s=1 pgs=0 cs=0 l=1 c=0x55ed2a28c600).register_pipe
2016-05-27 12:40:29.295422 7f5e3d4a4180 10 -- 10.100.23.2:6801/13844 get_connection mon.2 10.100.23.4:6789/0 new 0x55ed2a33a000
2016-05-27 12:40:29.295423 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=-1 :0 s=1 pgs=0 cs=0 l=1 c=0x55ed2a28c600).writer: state = connecting policy.server=0
2016-05-27 12:40:29.295438 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=-1 :0 s=1 pgs=0 cs=0 l=1 c=0x55ed2a28c600).connect 0
2016-05-27 12:40:29.295470 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :0 s=1 pgs=0 cs=0 l=1 c=0x55ed2a28c600).connecting to 10.100.23.4:6789/0
2016-05-27 12:40:29.295503 7f5e3d4a4180 1 -- 10.100.23.2:6801/13844 --> 10.100.23.4:6789/0 -- auth(proto 0 36 bytes epoch 0) v1 -- ?+0 0x55ed2a26e240 con 0x55ed2a28c600
2016-05-27 12:40:29.295868 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=1 pgs=0 cs=0 l=1 c=0x55ed2a28c600).connect sent my addr 10.100.23.2:6801/13844
2016-05-27 12:40:29.295892 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=1 pgs=0 cs=0 l=1 c=0x55ed2a28c600).connect sending gseq=1 cseq=0 proto=15
2016-05-27 12:40:29.295993 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).connect success 1, lossy = 1, features 576460752032874495
2016-05-27 12:40:29.296052 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.296063 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_keepalive2 14 2016-05-27 12:40:29.296062
2016-05-27 12:40:29.296101 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.296282 7f5e343b7700 2 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got KEEPALIVE_ACK
2016-05-27 12:40:29.374852 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 809 from dispatch throttler 0/104857600
2016-05-27 12:40:29.374887 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
2016-05-27 12:40:29.374967 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
2016-05-27 12:40:29.374979 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 1 0x55ed2a26e900 mon_map magic: 0 v1
2016-05-27 12:40:29.374998 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 33 from dispatch throttler 809/104857600
2016-05-27 12:40:29.374998 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.375006 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
2016-05-27 12:40:29.375007 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 1
2016-05-27 12:40:29.375013 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
2016-05-27 12:40:29.375008 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 1 ==== mon_map magic: 0 v1 ==== 809+0+0 (3484755534 0 0) 0x55ed2a26e900 con 0x55ed2a28c600
2016-05-27 12:40:29.375017 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 2 0x55ed2a26eb40 auth_reply(proto 2 0 (0) Success) v1
2016-05-27 12:40:29.375036 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.375053 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 2
2016-05-27 12:40:29.375060 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.375068 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 809 to dispatch throttler 842/104857600
2016-05-27 12:40:29.375077 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 2 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 33+0+0 (1531256007 0 0) 0x55ed2a26eb40 con 0x55ed2a28c600
2016-05-27 12:40:29.375162 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 --> 10.100.23.4:6789/0 -- auth(proto 2 32 bytes epoch 0) v1 -- ?+0 0x55ed2a26e900 con 0x55ed2a28c600
2016-05-27 12:40:29.375172 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 33 to dispatch throttler 33/104857600
2016-05-27 12:40:29.375174 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.375200 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.658181 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 222 from dispatch throttler 0/104857600
2016-05-27 12:40:29.658222 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
2016-05-27 12:40:29.658238 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
2016-05-27 12:40:29.658247 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 3 0x55ed2a26ed80 auth_reply(proto 2 0 (0) Success) v1
2016-05-27 12:40:29.658280 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.658293 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 3
2016-05-27 12:40:29.658290 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 3 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 222+0+0 (1030293739 0 0) 0x55ed2a26ed80 con 0x55ed2a28c600
2016-05-27 12:40:29.658304 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.658407 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 --> 10.100.23.4:6789/0 -- auth(proto 2 181 bytes epoch 0) v1 -- ?+0 0x55ed2a26eb40 con 0x55ed2a28c600
2016-05-27 12:40:29.658418 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 222 to dispatch throttler 222/104857600
2016-05-27 12:40:29.658420 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.658476 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.941818 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 612 from dispatch throttler 0/104857600
2016-05-27 12:40:29.941856 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
2016-05-27 12:40:29.941882 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
2016-05-27 12:40:29.941890 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 4 0x55ed2a26e240 auth_reply(proto 2 0 (0) Success) v1
2016-05-27 12:40:29.941920 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.941934 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 4
2016-05-27 12:40:29.941943 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.941955 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 4 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 612+0+0 (526588041 0 0) 0x55ed2a26e240 con 0x55ed2a28c600
2016-05-27 12:40:29.942103 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 --> 10.100.23.4:6789/0 -- mon_subscribe({monmap=0+}) v2 -- ?+0 0x55ed2a26b000 con 0x55ed2a28c600
2016-05-27 12:40:29.942123 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.942151 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 --> 10.100.23.4:6789/0 -- auth(proto 2 2 bytes epoch 0) v1 -- ?+0 0x55ed2a26ed80 con 0x55ed2a28c600
2016-05-27 12:40:29.942160 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 612 to dispatch throttler 612/104857600
2016-05-27 12:40:29.942164 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.942184 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.942450 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 809 from dispatch throttler 0/104857600
2016-05-27 12:40:29.942466 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
2016-05-27 12:40:29.942473 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
2016-05-27 12:40:29.942480 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 5 0x55ed2a26e900 mon_map magic: 0 v1
2016-05-27 12:40:29.942510 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.942525 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 5
2016-05-27 12:40:29.942524 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 5 ==== mon_map magic: 0 v1 ==== 809+0+0 (3484755534 0 0) 0x55ed2a26e900 con 0x55ed2a28c600
2016-05-27 12:40:29.942544 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.942549 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 194 from dispatch throttler 809/104857600
2016-05-27 12:40:29.942558 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
2016-05-27 12:40:29.942565 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
2016-05-27 12:40:29.942575 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 809 to dispatch throttler 1003/104857600
2016-05-27 12:40:29.942570 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 6 0x55ed2a26f200 auth_reply(proto 2 0 (0) Success) v1
2016-05-27 12:40:29.942591 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.942591 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 6 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 194+0+0 (4165303729 0 0) 0x55ed2a26f200 con 0x55ed2a28c600
2016-05-27 12:40:29.942597 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 6
2016-05-27 12:40:29.942603 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.942690 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 194 to dispatch throttler 194/104857600
2016-05-27 12:40:29.942730 7f5e3d4a4180 1 -- 10.100.23.2:6801/13844 --> 10.100.23.4:6789/0 -- mon_subscribe({osdmap=0}) v2 -- ?+0 0x55ed2a26b200 con 0x55ed2a28c600
2016-05-27 12:40:29.942741 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.942747 7f5e3d4a4180 1 -- 10.100.23.2:6801/13844 --> 10.100.23.4:6789/0 -- mon_subscribe({mdsmap=0+}) v2 -- ?+0 0x55ed2a26b600 con 0x55ed2a28c600
2016-05-27 12:40:29.942761 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.942780 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.943355 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 114667 from dispatch throttler 0/104857600
2016-05-27 12:40:29.943544 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
2016-05-27 12:40:29.943567 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
2016-05-27 12:40:29.943576 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 7 0x55ed2a26f440 osd_map(104845..104845 src has 72344..104845) v3
2016-05-27 12:40:29.943587 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 429 from dispatch throttler 114667/104857600
2016-05-27 12:40:29.943594 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
2016-05-27 12:40:29.943601 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
2016-05-27 12:40:29.943604 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.943618 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 7
2016-05-27 12:40:29.943617 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 7 ==== osd_map(104845..104845 src has 72344..104845) v3 ==== 114667+0+0 (3630699779 0 0) 0x55ed2a26f440 con 0x55ed2a28c600
2016-05-27 12:40:29.943622 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 8 0x55ed2a26f8c0 mdsmap(e 109393) v1
2016-05-27 12:40:29.943633 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.943639 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 8
2016-05-27 12:40:29.943643 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.944074 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 114667 to dispatch throttler 115096/104857600
2016-05-27 12:40:29.944095 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 8 ==== mdsmap(e 109393) v1 ==== 429+0+0 (3031777113 0 0) 0x55ed2a26f8c0 con 0x55ed2a28c600
2016-05-27 12:40:29.944134 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 429 to dispatch throttler 429/104857600
2016-05-27 12:40:29.963607 7f5e3d4a4180 1 -- 10.100.23.2:6801/13844 --> 10.100.23.4:6789/0 -- mdsbeacon(49216377/virt-master up:boot seq 1 v109393) v7 -- ?+0 0x55ed2a37a000 con 0x55ed2a28c600
2016-05-27 12:40:29.963643 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.963709 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:29.963735 7f5e3d4a4180 10 -- 10.100.23.2:6801/13844 wait: waiting for dispatch queue
2016-05-27 12:40:31.225812 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 655 from dispatch throttler 0/104857600
2016-05-27 12:40:31.225850 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
2016-05-27 12:40:31.225880 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
2016-05-27 12:40:31.225890 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 9 0x55ed2a26fb00 mdsmap(e 109394) v1
2016-05-27 12:40:31.225970 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 9 ==== mdsmap(e 109394) v1 ==== 655+0+0 (1262137681 0 0) 0x55ed2a26fb00 con 0x55ed2a28c600
2016-05-27 12:40:31.225976 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:31.225988 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 9
2016-05-27 12:40:31.225998 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:31.226050 7f5e36bbc700 1 mds.virt-master handle_mds_map standby
2016-05-27 12:40:31.226063 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 655 to dispatch throttler 655/104857600
2016-05-27 12:40:31.226433 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 140 from dispatch throttler 0/104857600
2016-05-27 12:40:31.226449 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
2016-05-27 12:40:31.226463 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
2016-05-27 12:40:31.226470 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 10 0x55ed2a37a340 mdsbeacon(49216377/virt-master up:boot seq 1 v109394) v7
2016-05-27 12:40:31.226497 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:31.226503 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 10 ==== mdsbeacon(49216377/virt-master up:boot seq 1 v109394) v7 ==== 140+0+0 (3084512335 0 0) 0x55ed2a37a340 con 0x55ed2a28c600
2016-05-27 12:40:31.226511 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 10
2016-05-27 12:40:31.226516 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 140 to dispatch throttler 140/104857600
2016-05-27 12:40:31.226520 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:31.509716 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 966 from dispatch throttler 0/104857600
2016-05-27 12:40:31.509771 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
2016-05-27 12:40:31.509790 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
2016-05-27 12:40:31.509800 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 11 0x55ed2a270f40 mdsmap(e 109395) v1
2016-05-27 12:40:31.509833 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:31.509847 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 11
2016-05-27 12:40:31.509844 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 11 ==== mdsmap(e 109395) v1 ==== 966+0+0 (13525258 0 0) 0x55ed2a270f40 con 0x55ed2a28c600
2016-05-27 12:40:31.509856 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:31.510074 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 --> 10.100.23.4:6789/0 -- mon_subscribe({osdmap=104846}) v2 -- ?+0 0x55ed2a26b000 con 0x55ed2a28c600
2016-05-27 12:40:31.510087 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:31.510113 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
2016-05-27 12:40:31.510187 7f5e36bbc700 1 mds.1.109395 handle_mds_map i am now mds.1.109395
2016-05-27 12:40:31.510193 7f5e36bbc700 1 mds.1.109395 handle_mds_map state change up:boot --> up:replay
2016-05-27 12:40:31.510206 7f5e36bbc700 1 mds.1.109395 replay_start
2016-05-27 12:40:31.510212 7f5e36bbc700 1 mds.1.109395 recovery set is 0
2016-05-27 12:40:31.510217 7f5e36bbc700 1 mds.1.109395 waiting for osdmap 104847 (which blacklists prior instance)
./mds/MDSMap.h: In function 'const entity_inst_t MDSMap::get_inst(mds_rank_t)' thread 7f5e36bbc700 time 2016-05-27 12:40:31.510224
./mds/MDSMap.h: 582: FAILED assert(up.count(m))
ceph version 10.2.1 (3a66dd4f30852819c1bdaa8ec23c795d4ad77269)
1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x82) [0x55ed20047152]
2: (MDSMap::get_inst(int)+0x21f) [0x55ed1fc797ff]
3: (MDSRankDispatcher::handle_mds_map(MMDSMap*, MDSMap*)+0x827) [0x55ed1fc6b7a7]
4: (MDSDaemon::handle_mds_map(MMDSMap*)+0xd16) [0x55ed1fc48946]
5: (MDSDaemon::handle_core_message(Message*)+0x783) [0x55ed1fc4a013]
6: (MDSDaemon::ms_dispatch(Message*)+0xdb) [0x55ed1fc4a2ab]
7: (DispatchQueue::entry()+0x7ba) [0x55ed2014f83a]
8: (DispatchQueue::DispatchThread::entry()+0xd) [0x55ed2002ba8d]
9: (()+0x80a4) [0x7f5e3cdc50a4]
10: (clone()+0x6d) [0x7f5e3b30d87d]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
2016-05-27 12:40:31.511594 7f5e36bbc700 -1 ./mds/MDSMap.h: In function 'const entity_inst_t MDSMap::get_inst(mds_rank_t)' thread 7f5e36bbc700 time 2016-05-27 12:40:31.510224
./mds/MDSMap.h: 582: FAILED assert(up.count(m))

ceph version 10.2.1 (3a66dd4f30852819c1bdaa8ec23c795d4ad77269)
1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x82) [0x55ed20047152]
2: (MDSMap::get_inst(int)+0x21f) [0x55ed1fc797ff]
3: (MDSRankDispatcher::handle_mds_map(MMDSMap*, MDSMap*)+0x827) [0x55ed1fc6b7a7]
4: (MDSDaemon::handle_mds_map(MMDSMap*)+0xd16) [0x55ed1fc48946]
5: (MDSDaemon::handle_core_message(Message*)+0x783) [0x55ed1fc4a013]
6: (MDSDaemon::ms_dispatch(Message*)+0xdb) [0x55ed1fc4a2ab]
7: (DispatchQueue::entry()+0x7ba) [0x55ed2014f83a]
8: (DispatchQueue::DispatchThread::entry()+0xd) [0x55ed2002ba8d]
9: (()+0x80a4) [0x7f5e3cdc50a4]
10: (clone()+0x6d) [0x7f5e3b30d87d]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- begin dump of recent events ---
-235> 2016-05-27 12:40:29.287841 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command perfcounters_dump hook 0x55ed2a24e030
-234> 2016-05-27 12:40:29.287883 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command 1 hook 0x55ed2a24e030
-233> 2016-05-27 12:40:29.287889 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command perf dump hook 0x55ed2a24e030
-232> 2016-05-27 12:40:29.287894 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command perfcounters_schema hook 0x55ed2a24e030
-231> 2016-05-27 12:40:29.287966 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command 2 hook 0x55ed2a24e030
-230> 2016-05-27 12:40:29.287981 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command perf schema hook 0x55ed2a24e030
-229> 2016-05-27 12:40:29.287986 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command perf reset hook 0x55ed2a24e030
-228> 2016-05-27 12:40:29.287990 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command config show hook 0x55ed2a24e030
-227> 2016-05-27 12:40:29.287994 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command config set hook 0x55ed2a24e030
-226> 2016-05-27 12:40:29.287999 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command config get hook 0x55ed2a24e030
-225> 2016-05-27 12:40:29.288003 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command config diff hook 0x55ed2a24e030
-224> 2016-05-27 12:40:29.288006 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command log flush hook 0x55ed2a24e030
-223> 2016-05-27 12:40:29.288010 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command log dump hook 0x55ed2a24e030
-222> 2016-05-27 12:40:29.288013 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command log reopen hook 0x55ed2a24e030
-221> 2016-05-27 12:40:29.292037 7f5e3d4a4180 0 set uid:gid to 64045:64045 (ceph:ceph)
-220> 2016-05-27 12:40:29.292049 7f5e3d4a4180 0 ceph version 10.2.1 (3a66dd4f30852819c1bdaa8ec23c795d4ad77269), process ceph-mds, pid 13844
-219> 2016-05-27 12:40:29.292790 7f5e3d4a4180 10 -- :/0 rank.bind 10.100.23.2:0/0
-218> 2016-05-27 12:40:29.292797 7f5e3d4a4180 10 accepter.accepter.bind
-217> 2016-05-27 12:40:29.292811 7f5e3d4a4180 10 accepter.accepter.bind bound on random port 10.100.23.2:6801/0
-216> 2016-05-27 12:40:29.292814 7f5e3d4a4180 10 accepter.accepter.bind bound to 10.100.23.2:6801/0
-215> 2016-05-27 12:40:29.292818 7f5e3d4a4180 1 -- 10.100.23.2:0/0 learned my addr 10.100.23.2:0/0
-214> 2016-05-27 12:40:29.292822 7f5e3d4a4180 1 accepter.accepter.bind my_inst.addr is 10.100.23.2:6801/13844 need_addr=0
-213> 2016-05-27 12:40:29.294462 7f5e3d4a4180 5 asok(0x55ed2a272000) init /var/run/ceph/ceph-mds.virt-master.asok
-212> 2016-05-27 12:40:29.294484 7f5e3d4a4180 5 asok(0x55ed2a272000) bind_and_listen /var/run/ceph/ceph-mds.virt-master.asok
-211> 2016-05-27 12:40:29.294561 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command 0 hook 0x55ed2a24a0a8
-210> 2016-05-27 12:40:29.294577 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command version hook 0x55ed2a24a0a8
-209> 2016-05-27 12:40:29.294582 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command git_version hook 0x55ed2a24a0a8
-208> 2016-05-27 12:40:29.294587 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command help hook 0x55ed2a24e1d0
-207> 2016-05-27 12:40:29.294591 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command get_command_descriptions hook 0x55ed2a24e1e0
-206> 2016-05-27 12:40:29.294630 7f5e3d4a4180 10 monclient(hunting): build_initial_monmap
-205> 2016-05-27 12:40:29.294642 7f5e383bf700 5 asok(0x55ed2a272000) entry start
-204> 2016-05-27 12:40:29.294670 7f5e3d4a4180 1 -- 10.100.23.2:6801/13844 messenger.start
-203> 2016-05-27 12:40:29.294733 7f5e3d4a4180 5 adding auth protocol: cephx
-202> 2016-05-27 12:40:29.294738 7f5e3d4a4180 5 adding auth protocol: cephx
-201> 2016-05-27 12:40:29.294738 7f5e37bbe700 10 -- 10.100.23.2:6801/13844 reaper_entry start
-200> 2016-05-27 12:40:29.294762 7f5e37bbe700 10 -- 10.100.23.2:6801/13844 reaper
-199> 2016-05-27 12:40:29.294765 7f5e37bbe700 10 -- 10.100.23.2:6801/13844 reaper done
-198> 2016-05-27 12:40:29.294891 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command objecter_requests hook 0x55ed2a24e1f0
-197> 2016-05-27 12:40:29.294923 7f5e3d4a4180 10 -- 10.100.23.2:6801/13844 ready 10.100.23.2:6801/13844
-196> 2016-05-27 12:40:29.294989 7f5e3d4a4180 1 accepter.accepter.start
-195> 2016-05-27 12:40:29.295062 7f5e3d4a4180 10 monclient(hunting): init
-194> 2016-05-27 12:40:29.295075 7f5e3d4a4180 5 adding auth protocol: cephx
-193> 2016-05-27 12:40:29.295078 7f5e3d4a4180 10 monclient(hunting): auth_supported 2 method cephx
-192> 2016-05-27 12:40:29.295079 7f5e35bba700 10 accepter.accepter starting
-191> 2016-05-27 12:40:29.295213 7f5e3d4a4180 2 auth: KeyRing::load: loaded key file /var/lib/ceph/mds/ceph-virt-master/keyring
-190> 2016-05-27 12:40:29.295357 7f5e3d4a4180 10 monclient(hunting): _reopen_session rank -1 name
-189> 2016-05-27 12:40:29.295363 7f5e3d4a4180 10 -- 10.100.23.2:6801/13844 connect_rank to 10.100.23.4:6789/0, creating pipe and registering
-188> 2016-05-27 12:40:29.295412 7f5e3d4a4180 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=-1 :0 s=1 pgs=0 cs=0 l=1 c=0x55ed2a28c600).register_pipe
-187> 2016-05-27 12:40:29.295422 7f5e3d4a4180 10 -- 10.100.23.2:6801/13844 get_connection mon.2 10.100.23.4:6789/0 new 0x55ed2a33a000
-186> 2016-05-27 12:40:29.295423 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=-1 :0 s=1 pgs=0 cs=0 l=1 c=0x55ed2a28c600).writer: state = connecting policy.server=0
-185> 2016-05-27 12:40:29.295438 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=-1 :0 s=1 pgs=0 cs=0 l=1 c=0x55ed2a28c600).connect 0
-184> 2016-05-27 12:40:29.295470 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :0 s=1 pgs=0 cs=0 l=1 c=0x55ed2a28c600).connecting to 10.100.23.4:6789/0
-183> 2016-05-27 12:40:29.295483 7f5e3d4a4180 10 monclient(hunting): picked mon.noname-c con 0x55ed2a28c600 addr 10.100.23.4:6789/0
-182> 2016-05-27 12:40:29.295499 7f5e3d4a4180 10 monclient(hunting): _send_mon_message to mon.noname-c at 10.100.23.4:6789/0
-181> 2016-05-27 12:40:29.295503 7f5e3d4a4180 1 -- 10.100.23.2:6801/13844 --> 10.100.23.4:6789/0 -- auth(proto 0 36 bytes epoch 0) v1 -- ?+0 0x55ed2a26e240 con 0x55ed2a28c600
-180> 2016-05-27 12:40:29.295520 7f5e3d4a4180 10 monclient(hunting): renew_subs
-179> 2016-05-27 12:40:29.295868 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=1 pgs=0 cs=0 l=1 c=0x55ed2a28c600).connect sent my addr 10.100.23.2:6801/13844
-178> 2016-05-27 12:40:29.295892 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=1 pgs=0 cs=0 l=1 c=0x55ed2a28c600).connect sending gseq=1 cseq=0 proto=15
-177> 2016-05-27 12:40:29.295993 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).connect success 1, lossy = 1, features 576460752032874495
-176> 2016-05-27 12:40:29.296052 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-175> 2016-05-27 12:40:29.296063 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_keepalive2 14 2016-05-27 12:40:29.296062
-174> 2016-05-27 12:40:29.296101 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-173> 2016-05-27 12:40:29.296282 7f5e343b7700 2 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got KEEPALIVE_ACK
-172> 2016-05-27 12:40:29.374852 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 809 from dispatch throttler 0/104857600
-171> 2016-05-27 12:40:29.374887 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
-170> 2016-05-27 12:40:29.374967 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
-169> 2016-05-27 12:40:29.374979 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 1 0x55ed2a26e900 mon_map magic: 0 v1
-168> 2016-05-27 12:40:29.374998 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 33 from dispatch throttler 809/104857600
-167> 2016-05-27 12:40:29.374998 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-166> 2016-05-27 12:40:29.375006 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
-165> 2016-05-27 12:40:29.375007 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 1
-164> 2016-05-27 12:40:29.375013 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
-163> 2016-05-27 12:40:29.375008 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 1 ==== mon_map magic: 0 v1 ==== 809+0+0 (3484755534 0 0) 0x55ed2a26e900 con 0x55ed2a28c600
-162> 2016-05-27 12:40:29.375024 7f5e36bbc700 10 monclient(hunting): handle_monmap mon_map magic: 0 v1
-161> 2016-05-27 12:40:29.375017 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 2 0x55ed2a26eb40 auth_reply(proto 2 0 (0) Success) v1
-160> 2016-05-27 12:40:29.375041 7f5e36bbc700 10 monclient(hunting): got monmap 17, mon.noname-c is now rank -1
-159> 2016-05-27 12:40:29.375036 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-158> 2016-05-27 12:40:29.375053 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 2
-157> 2016-05-27 12:40:29.375060 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-156> 2016-05-27 12:40:29.375048 7f5e36bbc700 10 monclient(hunting): dump:
epoch 17
fsid f53d4a19-b2c0-4a92-9620-bc6e3bfc27d6
last_changed 2015-02-27 20:09:51.147200
created 0.000000
0: 10.100.23.2:6789/0 mon.virt-master
1: 10.100.23.3:6789/0 mon.virt-node-02
2: 10.100.23.4:6789/0 mon.virt-node-03
3: 10.100.23.7:6789/0 mon.virt-node-05
4: 10.100.23.8:6789/0 mon.virt-node-06

-155> 2016-05-27 12:40:29.375068 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 809 to dispatch throttler 842/104857600
-154> 2016-05-27 12:40:29.375077 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 2 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 33+0+0 (1531256007 0 0) 0x55ed2a26eb40 con 0x55ed2a28c600
-153> 2016-05-27 12:40:29.375092 7f5e36bbc700 10 monclient(hunting): my global_id is 49216377
-152> 2016-05-27 12:40:29.375154 7f5e36bbc700 10 monclient(hunting): _send_mon_message to mon.virt-node-03 at 10.100.23.4:6789/0
-151> 2016-05-27 12:40:29.375162 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 --> 10.100.23.4:6789/0 -- auth(proto 2 32 bytes epoch 0) v1 -- ?+0 0x55ed2a26e900 con 0x55ed2a28c600
-150> 2016-05-27 12:40:29.375172 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 33 to dispatch throttler 33/104857600
-149> 2016-05-27 12:40:29.375174 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-148> 2016-05-27 12:40:29.375200 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-147> 2016-05-27 12:40:29.658181 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 222 from dispatch throttler 0/104857600
-146> 2016-05-27 12:40:29.658222 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
-145> 2016-05-27 12:40:29.658238 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
-144> 2016-05-27 12:40:29.658247 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 3 0x55ed2a26ed80 auth_reply(proto 2 0 (0) Success) v1
-143> 2016-05-27 12:40:29.658280 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-142> 2016-05-27 12:40:29.658293 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 3
-141> 2016-05-27 12:40:29.658290 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 3 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 222+0+0 (1030293739 0 0) 0x55ed2a26ed80 con 0x55ed2a28c600
-140> 2016-05-27 12:40:29.658304 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-139> 2016-05-27 12:40:29.658398 7f5e36bbc700 10 monclient(hunting): _send_mon_message to mon.virt-node-03 at 10.100.23.4:6789/0
-138> 2016-05-27 12:40:29.658407 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 --> 10.100.23.4:6789/0 -- auth(proto 2 181 bytes epoch 0) v1 -- ?+0 0x55ed2a26eb40 con 0x55ed2a28c600
-137> 2016-05-27 12:40:29.658418 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 222 to dispatch throttler 222/104857600
-136> 2016-05-27 12:40:29.658420 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-135> 2016-05-27 12:40:29.658476 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-134> 2016-05-27 12:40:29.941818 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 612 from dispatch throttler 0/104857600
-133> 2016-05-27 12:40:29.941856 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
-132> 2016-05-27 12:40:29.941882 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
-131> 2016-05-27 12:40:29.941890 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 4 0x55ed2a26e240 auth_reply(proto 2 0 (0) Success) v1
-130> 2016-05-27 12:40:29.941920 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-129> 2016-05-27 12:40:29.941934 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 4
-128> 2016-05-27 12:40:29.941943 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-127> 2016-05-27 12:40:29.941955 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 4 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 612+0+0 (526588041 0 0) 0x55ed2a26e240 con 0x55ed2a28c600
-126> 2016-05-27 12:40:29.942093 7f5e36bbc700 1 monclient(hunting): found mon.virt-node-03
-125> 2016-05-27 12:40:29.942097 7f5e36bbc700 10 monclient: _send_mon_message to mon.virt-node-03 at 10.100.23.4:6789/0
-124> 2016-05-27 12:40:29.942103 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 --> 10.100.23.4:6789/0 -- mon_subscribe({monmap=0+}) v2 -- ?+0 0x55ed2a26b000 con 0x55ed2a28c600
-123> 2016-05-27 12:40:29.942123 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-122> 2016-05-27 12:40:29.942125 7f5e36bbc700 10 monclient: _check_auth_rotating renewing rotating keys (they expired before 2016-05-27 12:39:59.942125)
-121> 2016-05-27 12:40:29.942147 7f5e36bbc700 10 monclient: _send_mon_message to mon.virt-node-03 at 10.100.23.4:6789/0
-120> 2016-05-27 12:40:29.942151 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 --> 10.100.23.4:6789/0 -- auth(proto 2 2 bytes epoch 0) v1 -- ?+0 0x55ed2a26ed80 con 0x55ed2a28c600
-119> 2016-05-27 12:40:29.942160 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 612 to dispatch throttler 612/104857600
-118> 2016-05-27 12:40:29.942165 7f5e3d4a4180 5 monclient: authenticate success, global_id 49216377
-117> 2016-05-27 12:40:29.942164 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-116> 2016-05-27 12:40:29.942172 7f5e3d4a4180 10 monclient: wait_auth_rotating waiting (until 2016-05-27 12:40:59.942171)
-115> 2016-05-27 12:40:29.942184 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-114> 2016-05-27 12:40:29.942450 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 809 from dispatch throttler 0/104857600
-113> 2016-05-27 12:40:29.942466 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
-112> 2016-05-27 12:40:29.942473 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
-111> 2016-05-27 12:40:29.942480 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 5 0x55ed2a26e900 mon_map magic: 0 v1
-110> 2016-05-27 12:40:29.942510 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-109> 2016-05-27 12:40:29.942525 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 5
-108> 2016-05-27 12:40:29.942524 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 5 ==== mon_map magic: 0 v1 ==== 809+0+0 (3484755534 0 0) 0x55ed2a26e900 con 0x55ed2a28c600
-107> 2016-05-27 12:40:29.942535 7f5e36bbc700 10 monclient: handle_monmap mon_map magic: 0 v1
-106> 2016-05-27 12:40:29.942544 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-105> 2016-05-27 12:40:29.942553 7f5e36bbc700 10 monclient: got monmap 17, mon.virt-node-03 is now rank 2
-104> 2016-05-27 12:40:29.942549 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 194 from dispatch throttler 809/104857600
-103> 2016-05-27 12:40:29.942558 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
-102> 2016-05-27 12:40:29.942565 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
-101> 2016-05-27 12:40:29.942555 7f5e36bbc700 10 monclient: dump:
epoch 17
fsid f53d4a19-b2c0-4a92-9620-bc6e3bfc27d6
last_changed 2015-02-27 20:09:51.147200
created 0.000000
0: 10.100.23.2:6789/0 mon.virt-master
1: 10.100.23.3:6789/0 mon.virt-node-02
2: 10.100.23.4:6789/0 mon.virt-node-03
3: 10.100.23.7:6789/0 mon.virt-node-05
4: 10.100.23.8:6789/0 mon.virt-node-06

-100> 2016-05-27 12:40:29.942575 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 809 to dispatch throttler 1003/104857600
-99> 2016-05-27 12:40:29.942570 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 6 0x55ed2a26f200 auth_reply(proto 2 0 (0) Success) v1
-98> 2016-05-27 12:40:29.942591 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-97> 2016-05-27 12:40:29.942591 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 6 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 194+0+0 (4165303729 0 0) 0x55ed2a26f200 con 0x55ed2a28c600
-96> 2016-05-27 12:40:29.942597 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 6
-95> 2016-05-27 12:40:29.942603 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-94> 2016-05-27 12:40:29.942678 7f5e36bbc700 10 monclient: _check_auth_rotating have uptodate secrets (they expire after 2016-05-27 12:39:59.942678)
-93> 2016-05-27 12:40:29.942690 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 194 to dispatch throttler 194/104857600
-92> 2016-05-27 12:40:29.942693 7f5e3d4a4180 10 monclient: wait_auth_rotating done
-91> 2016-05-27 12:40:29.942720 7f5e3d4a4180 10 monclient: renew_subs
-90> 2016-05-27 12:40:29.942724 7f5e3d4a4180 10 monclient: _send_mon_message to mon.virt-node-03 at 10.100.23.4:6789/0
-89> 2016-05-27 12:40:29.942730 7f5e3d4a4180 1 -- 10.100.23.2:6801/13844 --> 10.100.23.4:6789/0 -- mon_subscribe({osdmap=0}) v2 -- ?+0 0x55ed2a26b200 con 0x55ed2a28c600
-88> 2016-05-27 12:40:29.942742 7f5e3d4a4180 10 monclient: renew_subs
-87> 2016-05-27 12:40:29.942741 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-86> 2016-05-27 12:40:29.942745 7f5e3d4a4180 10 monclient: _send_mon_message to mon.virt-node-03 at 10.100.23.4:6789/0
-85> 2016-05-27 12:40:29.942747 7f5e3d4a4180 1 -- 10.100.23.2:6801/13844 --> 10.100.23.4:6789/0 -- mon_subscribe({mdsmap=0+}) v2 -- ?+0 0x55ed2a26b600 con 0x55ed2a28c600
-84> 2016-05-27 12:40:29.942761 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-83> 2016-05-27 12:40:29.942780 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-82> 2016-05-27 12:40:29.943355 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 114667 from dispatch throttler 0/104857600
-81> 2016-05-27 12:40:29.943544 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
-80> 2016-05-27 12:40:29.943567 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
-79> 2016-05-27 12:40:29.943576 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 7 0x55ed2a26f440 osd_map(104845..104845 src has 72344..104845) v3
-78> 2016-05-27 12:40:29.943587 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 429 from dispatch throttler 114667/104857600
-77> 2016-05-27 12:40:29.943594 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
-76> 2016-05-27 12:40:29.943601 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
-75> 2016-05-27 12:40:29.943604 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-74> 2016-05-27 12:40:29.943618 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 7
-73> 2016-05-27 12:40:29.943617 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 7 ==== osd_map(104845..104845 src has 72344..104845) v3 ==== 114667+0+0 (3630699779 0 0) 0x55ed2a26f440 con 0x55ed2a28c600
-72> 2016-05-27 12:40:29.943622 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 8 0x55ed2a26f8c0 mdsmap(e 109393) v1
-71> 2016-05-27 12:40:29.943633 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-70> 2016-05-27 12:40:29.943639 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 8
-69> 2016-05-27 12:40:29.943643 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-68> 2016-05-27 12:40:29.944074 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 114667 to dispatch throttler 115096/104857600
-67> 2016-05-27 12:40:29.944078 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command status hook 0x55ed2a24e230
-66> 2016-05-27 12:40:29.944086 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command dump_ops_in_flight hook 0x55ed2a24e230
-65> 2016-05-27 12:40:29.944089 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command ops hook 0x55ed2a24e230
-64> 2016-05-27 12:40:29.944095 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command dump_blocked_ops hook 0x55ed2a24e230
-63> 2016-05-27 12:40:29.944095 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 8 ==== mdsmap(e 109393) v1 ==== 429+0+0 (3031777113 0 0) 0x55ed2a26f8c0 con 0x55ed2a28c600
-62> 2016-05-27 12:40:29.944100 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command dump_historic_ops hook 0x55ed2a24e230
-61> 2016-05-27 12:40:29.944101 7f5e36bbc700 5 mds.virt-master handle_mds_map epoch 109393 from mon.2
-60> 2016-05-27 12:40:29.944104 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command scrub_path hook 0x55ed2a24e230
-59> 2016-05-27 12:40:29.944107 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command tag path hook 0x55ed2a24e230
-58> 2016-05-27 12:40:29.944111 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command flush_path hook 0x55ed2a24e230
-57> 2016-05-27 12:40:29.944114 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command export dir hook 0x55ed2a24e230
-56> 2016-05-27 12:40:29.944117 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command dump cache hook 0x55ed2a24e230
-55> 2016-05-27 12:40:29.944122 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command session evict hook 0x55ed2a24e230
-54> 2016-05-27 12:40:29.944126 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command osdmap barrier hook 0x55ed2a24e230
-53> 2016-05-27 12:40:29.944130 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command session ls hook 0x55ed2a24e230
-52> 2016-05-27 12:40:29.944134 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command flush journal hook 0x55ed2a24e230
-51> 2016-05-27 12:40:29.944134 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 429 to dispatch throttler 429/104857600
-50> 2016-05-27 12:40:29.944138 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command force_readonly hook 0x55ed2a24e230
-49> 2016-05-27 12:40:29.944140 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command get subtrees hook 0x55ed2a24e230
-48> 2016-05-27 12:40:29.944143 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command dirfrag split hook 0x55ed2a24e230
-47> 2016-05-27 12:40:29.944147 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command dirfrag merge hook 0x55ed2a24e230
-46> 2016-05-27 12:40:29.944150 7f5e3d4a4180 5 asok(0x55ed2a272000) register_command dirfrag ls hook 0x55ed2a24e230
-45> 2016-05-27 12:40:29.963583 7f5e3d4a4180 10 monclient: _send_mon_message to mon.virt-node-03 at 10.100.23.4:6789/0
-44> 2016-05-27 12:40:29.963607 7f5e3d4a4180 1 -- 10.100.23.2:6801/13844 --> 10.100.23.4:6789/0 -- mdsbeacon(49216377/virt-master up:boot seq 1 v109393) v7 -- ?+0 0x55ed2a37a000 con 0x55ed2a28c600
-43> 2016-05-27 12:40:29.963643 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-42> 2016-05-27 12:40:29.963709 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-41> 2016-05-27 12:40:29.963735 7f5e3d4a4180 10 -- 10.100.23.2:6801/13844 wait: waiting for dispatch queue
-40> 2016-05-27 12:40:31.225812 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 655 from dispatch throttler 0/104857600
-39> 2016-05-27 12:40:31.225850 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
-38> 2016-05-27 12:40:31.225880 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
-37> 2016-05-27 12:40:31.225890 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 9 0x55ed2a26fb00 mdsmap(e 109394) v1
-36> 2016-05-27 12:40:31.225970 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 9 ==== mdsmap(e 109394) v1 ==== 655+0+0 (1262137681 0 0) 0x55ed2a26fb00 con 0x55ed2a28c600
-35> 2016-05-27 12:40:31.225976 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-34> 2016-05-27 12:40:31.225988 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 9
-33> 2016-05-27 12:40:31.225995 7f5e36bbc700 5 mds.virt-master handle_mds_map epoch 109394 from mon.2
-32> 2016-05-27 12:40:31.225998 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-31> 2016-05-27 12:40:31.226050 7f5e36bbc700 1 mds.virt-master handle_mds_map standby
-30> 2016-05-27 12:40:31.226063 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 655 to dispatch throttler 655/104857600
-29> 2016-05-27 12:40:31.226433 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 140 from dispatch throttler 0/104857600
-28> 2016-05-27 12:40:31.226449 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
-27> 2016-05-27 12:40:31.226463 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
-26> 2016-05-27 12:40:31.226470 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 10 0x55ed2a37a340 mdsbeacon(49216377/virt-master up:boot seq 1 v109394) v7
-25> 2016-05-27 12:40:31.226497 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-24> 2016-05-27 12:40:31.226503 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 10 ==== mdsbeacon(49216377/virt-master up:boot seq 1 v109394) v7 ==== 140+0+0 (3084512335 0 0) 0x55ed2a37a340 con 0x55ed2a28c600
-23> 2016-05-27 12:40:31.226511 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 10
-22> 2016-05-27 12:40:31.226516 7f5e36bbc700 10 -- 10.100.23.2:6801/13844 dispatch_throttle_release 140 to dispatch throttler 140/104857600
-21> 2016-05-27 12:40:31.226520 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-20> 2016-05-27 12:40:31.509716 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader wants 966 from dispatch throttler 0/104857600
-19> 2016-05-27 12:40:31.509771 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).aborted = 0
-18> 2016-05-27 12:40:31.509790 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).No session security set
-17> 2016-05-27 12:40:31.509800 7f5e343b7700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).reader got message 11 0x55ed2a270f40 mdsmap(e 109395) v1
-16> 2016-05-27 12:40:31.509833 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-15> 2016-05-27 12:40:31.509847 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).write_ack 11
-14> 2016-05-27 12:40:31.509844 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 <== mon.2 10.100.23.4:6789/0 11 ==== mdsmap(e 109395) v1 ==== 966+0+0 (13525258 0 0) 0x55ed2a270f40 con 0x55ed2a28c600
-13> 2016-05-27 12:40:31.509856 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-12> 2016-05-27 12:40:31.509861 7f5e36bbc700 5 mds.virt-master handle_mds_map epoch 109395 from mon.2
-11> 2016-05-27 12:40:31.510008 7f5e36bbc700 10 log_channel(cluster) update_config to_monitors: true to_syslog: false syslog_facility: daemon prio: info to_graylog: false graylog_host: 127.0.0.1 graylog_port: 12201)
-10> 2016-05-27 12:40:31.510057 7f5e36bbc700 10 monclient: renew_subs
-9> 2016-05-27 12:40:31.510064 7f5e36bbc700 10 monclient: _send_mon_message to mon.virt-node-03 at 10.100.23.4:6789/0
-8> 2016-05-27 12:40:31.510074 7f5e36bbc700 1 -- 10.100.23.2:6801/13844 --> 10.100.23.4:6789/0 -- mon_subscribe({osdmap=104846}) v2 -- ?+0 0x55ed2a26b000 con 0x55ed2a28c600
-7> 2016-05-27 12:40:31.510087 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-6> 2016-05-27 12:40:31.510113 7f5e3d4a0700 10 -- 10.100.23.2:6801/13844 >> 10.100.23.4:6789/0 pipe(0x55ed2a33a000 sd=8 :51936 s=2 pgs=5894591 cs=1 l=1 c=0x55ed2a28c600).writer: state = open policy.server=0
-5> 2016-05-27 12:40:31.510187 7f5e36bbc700 1 mds.1.109395 handle_mds_map i am now mds.1.109395
-4> 2016-05-27 12:40:31.510193 7f5e36bbc700 1 mds.1.109395 handle_mds_map state change up:boot --> up:replay
-3> 2016-05-27 12:40:31.510206 7f5e36bbc700 1 mds.1.109395 replay_start
-2> 2016-05-27 12:40:31.510212 7f5e36bbc700 1 mds.1.109395 recovery set is 0
-1> 2016-05-27 12:40:31.510217 7f5e36bbc700 1 mds.1.109395 waiting for osdmap 104847 (which blacklists prior instance)
0> 2016-05-27 12:40:31.511594 7f5e36bbc700 -1 ./mds/MDSMap.h: In function 'const entity_inst_t MDSMap::get_inst(mds_rank_t)' thread 7f5e36bbc700 time 2016-05-27 12:40:31.510224
./mds/MDSMap.h: 582: FAILED assert(up.count(m))

ceph version 10.2.1 (3a66dd4f30852819c1bdaa8ec23c795d4ad77269)
1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x82) [0x55ed20047152]
2: (MDSMap::get_inst(int)+0x21f) [0x55ed1fc797ff]
3: (MDSRankDispatcher::handle_mds_map(MMDSMap*, MDSMap*)+0x827) [0x55ed1fc6b7a7]
4: (MDSDaemon::handle_mds_map(MMDSMap*)+0xd16) [0x55ed1fc48946]
5: (MDSDaemon::handle_core_message(Message*)+0x783) [0x55ed1fc4a013]
6: (MDSDaemon::ms_dispatch(Message*)+0xdb) [0x55ed1fc4a2ab]
7: (DispatchQueue::entry()+0x7ba) [0x55ed2014f83a]
8: (DispatchQueue::DispatchThread::entry()+0xd) [0x55ed2002ba8d]
9: (()+0x80a4) [0x7f5e3cdc50a4]
10: (clone()+0x6d) [0x7f5e3b30d87d]
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
1/ 5 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 rbd_mirror
0/ 5 rbd_replay
0/ 5 journaler
0/ 5 objectcacher
0/ 5 client
0/ 5 osd
0/ 5 optracker
0/ 5 objclass
1/ 3 filestore
1/ 3 journal
10/10 ms
1/ 5 mon
0/10 monc
1/ 5 paxos
0/ 5 tp
1/ 5 auth
1/ 5 crypto
1/ 1 finisher
1/ 5 heartbeatmap
1/ 5 perfcounter
1/ 5 rgw
1/10 civetweb
1/ 5 javaclient
1/ 5 asok
1/ 1 throttle
0/ 0 refs
1/ 5 xio
1/ 5 compressor
1/ 5 newstore
1/ 5 bluestore
1/ 5 bluefs
1/ 3 bdev
1/ 5 kstore
4/ 5 rocksdb
4/ 5 leveldb
1/ 5 kinetic
1/ 5 fuse
-2/-2 (syslog threshold)
99/99 (stderr threshold)
max_recent 10000
max_new 1000
log_file
--- end dump of recent events ---
*** Caught signal (Aborted) **
in thread 7f5e36bbc700 thread_name:ms_dispatch
ceph version 10.2.1 (3a66dd4f30852819c1bdaa8ec23c795d4ad77269)
1: (()+0x4f88c7) [0x55ed1ff428c7]
2: (()+0xf8d0) [0x7f5e3cdcc8d0]
3: (gsignal()+0x37) [0x7f5e3b25a067]
4: (abort()+0x148) [0x7f5e3b25b448]
5: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x256) [0x55ed20047326]
6: (MDSMap::get_inst(int)+0x21f) [0x55ed1fc797ff]
7: (MDSRankDispatcher::handle_mds_map(MMDSMap*, MDSMap*)+0x827) [0x55ed1fc6b7a7]
8: (MDSDaemon::handle_mds_map(MMDSMap*)+0xd16) [0x55ed1fc48946]
9: (MDSDaemon::handle_core_message(Message*)+0x783) [0x55ed1fc4a013]
10: (MDSDaemon::ms_dispatch(Message*)+0xdb) [0x55ed1fc4a2ab]
11: (DispatchQueue::entry()+0x7ba) [0x55ed2014f83a]
12: (DispatchQueue::DispatchThread::entry()+0xd) [0x55ed2002ba8d]
13: (()+0x80a4) [0x7f5e3cdc50a4]
14: (clone()+0x6d) [0x7f5e3b30d87d]
2016-05-27 12:40:31.514436 7f5e36bbc700 -1 *** Caught signal (Aborted) **
in thread 7f5e36bbc700 thread_name:ms_dispatch

ceph version 10.2.1 (3a66dd4f30852819c1bdaa8ec23c795d4ad77269)
1: (()+0x4f88c7) [0x55ed1ff428c7]
2: (()+0xf8d0) [0x7f5e3cdcc8d0]
3: (gsignal()+0x37) [0x7f5e3b25a067]
4: (abort()+0x148) [0x7f5e3b25b448]
5: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x256) [0x55ed20047326]
6: (MDSMap::get_inst(int)+0x21f) [0x55ed1fc797ff]
7: (MDSRankDispatcher::handle_mds_map(MMDSMap*, MDSMap*)+0x827) [0x55ed1fc6b7a7]
8: (MDSDaemon::handle_mds_map(MMDSMap*)+0xd16) [0x55ed1fc48946]
9: (MDSDaemon::handle_core_message(Message*)+0x783) [0x55ed1fc4a013]
10: (MDSDaemon::ms_dispatch(Message*)+0xdb) [0x55ed1fc4a2ab]
11: (DispatchQueue::entry()+0x7ba) [0x55ed2014f83a]
12: (DispatchQueue::DispatchThread::entry()+0xd) [0x55ed2002ba8d]
13: (()+0x80a4) [0x7f5e3cdc50a4]
14: (clone()+0x6d) [0x7f5e3b30d87d]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- begin dump of recent events ---
0> 2016-05-27 12:40:31.514436 7f5e36bbc700 -1 *** Caught signal (Aborted) **
in thread 7f5e36bbc700 thread_name:ms_dispatch

ceph version 10.2.1 (3a66dd4f30852819c1bdaa8ec23c795d4ad77269)
1: (()+0x4f88c7) [0x55ed1ff428c7]
2: (()+0xf8d0) [0x7f5e3cdcc8d0]
3: (gsignal()+0x37) [0x7f5e3b25a067]
4: (abort()+0x148) [0x7f5e3b25b448]
5: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x256) [0x55ed20047326]
6: (MDSMap::get_inst(int)+0x21f) [0x55ed1fc797ff]
7: (MDSRankDispatcher::handle_mds_map(MMDSMap*, MDSMap*)+0x827) [0x55ed1fc6b7a7]
8: (MDSDaemon::handle_mds_map(MMDSMap*)+0xd16) [0x55ed1fc48946]
9: (MDSDaemon::handle_core_message(Message*)+0x783) [0x55ed1fc4a013]
10: (MDSDaemon::ms_dispatch(Message*)+0xdb) [0x55ed1fc4a2ab]
11: (DispatchQueue::entry()+0x7ba) [0x55ed2014f83a]
12: (DispatchQueue::DispatchThread::entry()+0xd) [0x55ed2002ba8d]
13: (()+0x80a4) [0x7f5e3cdc50a4]
14: (clone()+0x6d) [0x7f5e3b30d87d]
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
1/ 5 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 rbd_mirror
0/ 5 rbd_replay
0/ 5 journaler
0/ 5 objectcacher
0/ 5 client
0/ 5 osd
0/ 5 optracker
0/ 5 objclass
1/ 3 filestore
1/ 3 journal
10/10 ms
1/ 5 mon
0/10 monc
1/ 5 paxos
0/ 5 tp
1/ 5 auth
1/ 5 crypto
1/ 1 finisher
1/ 5 heartbeatmap
1/ 5 perfcounter
1/ 5 rgw
1/10 civetweb
1/ 5 javaclient
1/ 5 asok
1/ 1 throttle
0/ 0 refs
1/ 5 xio
1/ 5 compressor
1/ 5 newstore
1/ 5 bluestore
1/ 5 bluefs
1/ 3 bdev
1/ 5 kstore
4/ 5 rocksdb
4/ 5 leveldb
1/ 5 kinetic
1/ 5 fuse
-2/-2 (syslog threshold)
99/99 (stderr threshold)
max_recent 10000
max_new 1000
log_file
--- end dump of recent events ---
Aborted
(2-2/2)