Project

General

Profile

Bug #23463 » ceph-osd.0.log

Christian Wahl, 07/17/2019 03:55 PM

 
--- begin dump of recent events ---
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command abort hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command perfcounters_dump hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command 1 hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command perf dump hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command perfcounters_schema hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command perf histogram dump hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command 2 hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command perf schema hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command perf histogram schema hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command perf reset hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command config show hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command config help hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command config set hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command config unset hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command config get hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command config diff hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command config diff get hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command log flush hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command log dump hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command log reopen hook 0x56216e9b4460
-486> 2019-07-17 17:52:28.893 7f511ec32d80 5 asok(0x56216e9de5a0) register_command dump_mempools hook 0x56216e9ec2c8
-486> 2019-07-17 17:52:28.904 7f511ec32d80 10 monclient: get_monmap_and_config
-486> 2019-07-17 17:52:28.957 7f511ec32d80 10 monclient: build_initial_monmap
-486> 2019-07-17 17:52:28.959 7f510e919700 2 Event(0x56216ed10880 nevent=5000 time_id=1).set_owner idx=0 owner=139986113500928
-486> 2019-07-17 17:52:28.959 7f510e118700 2 Event(0x56216ed11480 nevent=5000 time_id=1).set_owner idx=1 owner=139986105108224
-486> 2019-07-17 17:52:28.959 7f510e919700 20 Event(0x56216ed10880 nevent=5000 time_id=1).create_file_event create event started fd=5 mask=1 original mask is 0
-486> 2019-07-17 17:52:28.959 7f510e919700 20 EpollDriver.add_event add event fd=5 cur_mask=0 add_mask=1 to 4
-486> 2019-07-17 17:52:28.959 7f510e118700 20 Event(0x56216ed11480 nevent=5000 time_id=1).create_file_event create event started fd=8 mask=1 original mask is 0
-486> 2019-07-17 17:52:28.959 7f510e118700 20 EpollDriver.add_event add event fd=8 cur_mask=0 add_mask=1 to 7
-486> 2019-07-17 17:52:28.959 7f510e919700 20 Event(0x56216ed10880 nevent=5000 time_id=1).create_file_event create event end fd=5 mask=1 original mask is 1
-486> 2019-07-17 17:52:28.959 7f510d917700 2 Event(0x56216ed11880 nevent=5000 time_id=1).set_owner idx=2 owner=139986096715520
-486> 2019-07-17 17:52:28.959 7f510e919700 10 stack operator() starting
-486> 2019-07-17 17:52:28.959 7f510e118700 20 Event(0x56216ed11480 nevent=5000 time_id=1).create_file_event create event end fd=8 mask=1 original mask is 1
-486> 2019-07-17 17:52:28.959 7f510e118700 10 stack operator() starting
-486> 2019-07-17 17:52:28.959 7f510d917700 20 Event(0x56216ed11880 nevent=5000 time_id=1).create_file_event create event started fd=11 mask=1 original mask is 0
-486> 2019-07-17 17:52:28.959 7f510d917700 20 EpollDriver.add_event add event fd=11 cur_mask=0 add_mask=1 to 10
-486> 2019-07-17 17:52:28.959 7f510d917700 20 Event(0x56216ed11880 nevent=5000 time_id=1).create_file_event create event end fd=11 mask=1 original mask is 1
-486> 2019-07-17 17:52:28.959 7f510d917700 10 stack operator() starting
-486> 2019-07-17 17:52:28.959 7f511ec32d80 10 -- - ready -
-486> 2019-07-17 17:52:28.959 7f511ec32d80 1 Processor -- start
-486> 2019-07-17 17:52:28.959 7f511ec32d80 1 -- - start start
-486> 2019-07-17 17:52:28.959 7f511ec32d80 10 monclient: init
-486> 2019-07-17 17:52:28.959 7f511ec32d80 5 adding auth protocol: cephx
-486> 2019-07-17 17:52:28.959 7f511ec32d80 10 monclient: auth_supported 2 method cephx
-486> 2019-07-17 17:52:28.959 7f511ec32d80 2 auth: KeyRing::load: loaded key file /var/lib/ceph/osd/ceph-0/keyring
-486> 2019-07-17 17:52:28.959 7f511ec32d80 10 monclient: _reopen_session rank -1
-486> 2019-07-17 17:52:28.959 7f511ec32d80 10 -- - create_connect 129.13.170.240:6789/0, creating connection and registering
-486> 2019-07-17 17:52:28.959 7f511ec32d80 10 -- - >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_NONE pgs=0 cs=0 l=0)._connect csq=0
-486> 2019-07-17 17:52:28.959 7f511ec32d80 20 Event(0x56216ed11480 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:28.959 7f511ec32d80 10 -- - get_connection mon.0 129.13.170.240:6789/0 new 0x56216ea18c00
-486> 2019-07-17 17:52:28.959 7f511ec32d80 10 monclient(hunting): picked mon.noname-a con 0x56216ea18c00 addr 129.13.170.240:6789/0
-486> 2019-07-17 17:52:28.959 7f511ec32d80 10 -- - >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING pgs=0 cs=0 l=0).send_keepalive
-486> 2019-07-17 17:52:28.959 7f511ec32d80 20 Event(0x56216ed11480 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:28.959 7f511ec32d80 1 -- - --> 129.13.170.240:6789/0 -- auth(proto 0 26 bytes epoch 0) v1 -- 0x56216e9af200 con 0
-486> 2019-07-17 17:52:28.960 7f511ec32d80 15 -- - >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING pgs=0 cs=0 l=0).send_message inline write is denied, reschedule m=0x56216e9af200
-486> 2019-07-17 17:52:28.960 7f511ec32d80 10 monclient(hunting): _renew_subs
-486> 2019-07-17 17:52:28.959 7f510e118700 20 -- - >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING pgs=0 cs=0 l=0).process prev state is STATE_CONNECTING
-486> 2019-07-17 17:52:28.960 7f511ec32d80 10 monclient(hunting): authenticate will time out at 2019-07-17 17:57:28.960600
-486> 2019-07-17 17:52:28.960 7f510e118700 20 Event(0x56216ed11480 nevent=5000 time_id=1).create_file_event create event started fd=13 mask=1 original mask is 0
-486> 2019-07-17 17:52:28.960 7f510e118700 20 EpollDriver.add_event add event fd=13 cur_mask=0 add_mask=1 to 7
-486> 2019-07-17 17:52:28.960 7f510e118700 20 Event(0x56216ed11480 nevent=5000 time_id=1).create_file_event create event end fd=13 mask=1 original mask is 1
-486> 2019-07-17 17:52:28.960 7f510e118700 20 -- - >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_RE pgs=0 cs=0 l=0).process prev state is STATE_CONNECTING
-486> 2019-07-17 17:52:28.960 7f510e118700 20 EpollDriver.del_event del event fd=13 cur_mask=1 delmask=2 to 7
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- - >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_RE pgs=0 cs=0 l=0)._process_connection connect successfully, ready to send banner
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- - >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_RE pgs=0 cs=0 l=0)._try_send sent bytes 9 remaining bytes 0
-486> 2019-07-17 17:52:28.960 7f510e118700 20 Event(0x56216ed11480 nevent=5000 time_id=1).create_file_event create event started fd=13 mask=2 original mask is 1
-486> 2019-07-17 17:52:28.960 7f510e118700 20 EpollDriver.add_event add event fd=13 cur_mask=1 add_mask=2 to 7
-486> 2019-07-17 17:52:28.960 7f510e118700 20 Event(0x56216ed11480 nevent=5000 time_id=1).create_file_event create event end fd=13 mask=2 original mask is 3
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- - >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY pgs=0 cs=0 l=0)._process_connection connect write banner done: 129.13.170.240:6789/0
-486> 2019-07-17 17:52:28.960 7f510e118700 20 -- - >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY pgs=0 cs=0 l=0).process prev state is STATE_CONNECTING_RE
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- - >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY pgs=0 cs=0 l=0).handle_write
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- - >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY pgs=0 cs=0 l=0)._try_send sent bytes 0 remaining bytes 0
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- - >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY pgs=0 cs=0 l=0).handle_write
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- - >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY pgs=0 cs=0 l=0)._try_send sent bytes 0 remaining bytes 0
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- - >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY pgs=0 cs=0 l=0).handle_write
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- - >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY pgs=0 cs=0 l=0)._try_send sent bytes 0 remaining bytes 0
-486> 2019-07-17 17:52:28.960 7f510e118700 20 -- - >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY pgs=0 cs=0 l=0).process prev state is STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY
-486> 2019-07-17 17:52:28.960 7f510e118700 20 -- - >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY pgs=0 cs=0 l=0)._process_connection connect read peer addr 129.13.170.240:6789/0 on socket 13
-486> 2019-07-17 17:52:28.960 7f510e118700 20 -- - >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY pgs=0 cs=0 l=0)._process_connection connect peer addr for me is 129.13.170.240:55154/0
-486> 2019-07-17 17:52:28.960 7f510e118700 1 -- 129.13.170.240:0/1461896717 learned_addr learned my addr 129.13.170.240:0/1461896717
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY pgs=0 cs=0 l=0)._try_send sent bytes 136 remaining bytes 0
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_SEND_CONNECT_MSG pgs=0 cs=0 l=0)._process_connection connect sent my addr 129.13.170.240:0/1461896717
-486> 2019-07-17 17:52:28.960 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_SEND_CONNECT_MSG pgs=0 cs=0 l=0).process prev state is STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_SEND_CONNECT_MSG pgs=0 cs=0 l=0)._process_connection connect sending gseq=1 cseq=0 proto=15
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_SEND_CONNECT_MSG pgs=0 cs=0 l=0)._try_send sent bytes 33 remaining bytes 0
-486> 2019-07-17 17:52:28.960 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY pgs=0 cs=0 l=0)._process_connection connect wrote (self +) cseq, waiting for reply
-486> 2019-07-17 17:52:28.960 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY pgs=0 cs=0 l=0).process prev state is STATE_CONNECTING_SEND_CONNECT_MSG
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY pgs=0 cs=0 l=0).handle_write
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY pgs=0 cs=0 l=0)._try_send sent bytes 0 remaining bytes 0
-486> 2019-07-17 17:52:28.960 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY pgs=0 cs=0 l=0).process prev state is STATE_CONNECTING_WAIT_CONNECT_REPLY
-486> 2019-07-17 17:52:28.960 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY pgs=0 cs=0 l=0)._process_connection connect got reply tag 13 connect_seq 1 global_seq 332 proto 15 flags 1 features 4611087854031667195
-486> 2019-07-17 17:52:28.960 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY_AUTH pgs=0 cs=0 l=0).process prev state is STATE_CONNECTING_WAIT_CONNECT_REPLY
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY_AUTH pgs=0 cs=0 l=0).handle_connect_reply got CEPH_MSGR_TAG_SEQ, reading acked_seq and writing in_seq
-486> 2019-07-17 17:52:28.960 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=0).process prev state is STATE_CONNECTING_WAIT_CONNECT_REPLY_AUTH
-486> 2019-07-17 17:52:28.960 7f510e118700 2 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=0)._process_connection got newly_acked_seq 0 vs out_seq 0
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=0).discard_requeued_up_to 0
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=0)._try_send sent bytes 8 remaining bytes 0
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_READY pgs=0 cs=0 l=0)._process_connection send in_seq done
-486> 2019-07-17 17:52:28.960 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_CONNECTING_READY pgs=0 cs=0 l=0).process prev state is STATE_CONNECTING_WAIT_ACK_SEQ
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1)._process_connection connect success 1, lossy = 1, features 4611087854031667195
-486> 2019-07-17 17:52:28.960 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).process prev state is STATE_CONNECTING_READY
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).handle_write
-486> 2019-07-17 17:52:28.960 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1)._append_keepalive_or_ack
-486> 2019-07-17 17:52:28.960 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).prepare_send_message m auth(proto 0 26 bytes epoch 0) v1
-486> 2019-07-17 17:52:28.960 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).prepare_send_message encoding features 4611087854031667195 0x56216e9af200 auth(proto 0 26 bytes epoch 0) v1
-486> 2019-07-17 17:52:28.960 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).write_message no session security
-486> 2019-07-17 17:52:28.960 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).write_message sending message type=17 src client.? front=56 data=0 off 0
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).write_message sending 1 0x56216e9af200
-486> 2019-07-17 17:52:28.961 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1)._try_send sent bytes 140 remaining bytes 0
-486> 2019-07-17 17:52:28.961 7f510e118700 20 EpollDriver.del_event del event fd=13 cur_mask=3 delmask=2 to 7
-486> 2019-07-17 17:52:28.961 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).write_message sending 0x56216e9af200 done.
-486> 2019-07-17 17:52:28.961 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).handle_write
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).process prev state is STATE_OPEN
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_KEEPALIVE2_ACK pgs=332 cs=1 l=1).process prev state is STATE_OPEN
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_KEEPALIVE2_ACK pgs=332 cs=1 l=1).process got KEEPALIVE_ACK
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).process prev state is STATE_OPEN_KEEPALIVE2_ACK
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).process prev state is STATE_OPEN
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process prev state is STATE_OPEN
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process begin MSG
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process got MSG header
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process got envelope type=4 src mon.0 front=187 data=0 off 0
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_THROTTLE_MESSAGE pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_HEADER
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_THROTTLE_BYTES pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_THROTTLE_MESSAGE
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_THROTTLE_DISPATCH_QUEUE pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_THROTTLE_BYTES
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FRONT pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_THROTTLE_DISPATCH_QUEUE
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FRONT pgs=332 cs=1 l=1).process got front 187
-486> 2019-07-17 17:52:28.961 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1).process aborted = 0
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1).process got 187 + 0 + 0 byte message
-486> 2019-07-17 17:52:28.961 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1).process no session security set
-486> 2019-07-17 17:52:28.961 7f510e118700 5 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1). rx mon.0 seq 1 0x56216e9af200 mon_map magic: 0 v1
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 queue 0x56216e9af200 prio 196
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_READ_FRONT
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process prev state is STATE_OPEN
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process begin MSG
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process got MSG header
-486> 2019-07-17 17:52:28.961 7f510d116700 1 -- 129.13.170.240:0/1461896717 <== mon.0 129.13.170.240:6789/0 1 ==== mon_map magic: 0 v1 ==== 187+0+0 (1830997952 0 0) 0x56216e9af200 con 0x56216ea18c00
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process got envelope type=18 src mon.0 front=33 data=0 off 0
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_THROTTLE_MESSAGE pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_HEADER
-486> 2019-07-17 17:52:28.961 7f510d116700 10 monclient(hunting): handle_monmap mon_map magic: 0 v1
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_THROTTLE_BYTES pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_THROTTLE_MESSAGE
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_THROTTLE_DISPATCH_QUEUE pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_THROTTLE_BYTES
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FRONT pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_THROTTLE_DISPATCH_QUEUE
-486> 2019-07-17 17:52:28.961 7f510d116700 10 monclient(hunting): got monmap 3, mon.noname-a is now rank -1
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FRONT pgs=332 cs=1 l=1).process got front 33
-486> 2019-07-17 17:52:28.961 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1).process aborted = 0
-486> 2019-07-17 17:52:28.961 7f510d116700 10 monclient(hunting): dump:
epoch 3
fsid a9493143-3e4e-450e-b3b8-28508d48d412
last_changed 2019-01-22 16:57:46.780494
created 2018-05-28 22:41:11.854539
0: 129.13.170.240:6789/0 mon.mon01

-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1).process got 33 + 0 + 0 byte message
-486> 2019-07-17 17:52:28.961 7f510d116700 10 -- 129.13.170.240:0/1461896717 dispatch_throttle_release 187 to dispatch throttler 220/104857600
-486> 2019-07-17 17:52:28.961 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1).process no session security set
-486> 2019-07-17 17:52:28.961 7f510d116700 20 -- 129.13.170.240:0/1461896717 done calling dispatch on 0x56216e9af200
-486> 2019-07-17 17:52:28.961 7f510e118700 5 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1). rx mon.0 seq 2 0x56216e9afd40 auth_reply(proto 2 0 (0) Success) v1
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 queue 0x56216e9afd40 prio 196
-486> 2019-07-17 17:52:28.961 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_READ_FRONT
-486> 2019-07-17 17:52:28.961 7f510d116700 1 -- 129.13.170.240:0/1461896717 <== mon.0 129.13.170.240:6789/0 2 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 33+0+0 (1674873472 0 0) 0x56216e9afd40 con 0x56216ea18c00
-486> 2019-07-17 17:52:28.961 7f510d116700 10 monclient(hunting): my global_id is 4204427
-486> 2019-07-17 17:52:28.962 7f510d116700 1 -- 129.13.170.240:0/1461896717 --> 129.13.170.240:6789/0 -- auth(proto 2 32 bytes epoch 0) v1 -- 0x56216e9af200 con 0
-486> 2019-07-17 17:52:28.962 7f510d116700 15 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).send_message inline write is denied, reschedule m=0x56216e9af200
-486> 2019-07-17 17:52:28.962 7f510d116700 20 Event(0x56216ed11480 nevent=5000 time_id=2).wakeup
-486> 2019-07-17 17:52:28.962 7f510d116700 10 -- 129.13.170.240:0/1461896717 dispatch_throttle_release 33 to dispatch throttler 33/104857600
-486> 2019-07-17 17:52:28.962 7f510d116700 20 -- 129.13.170.240:0/1461896717 done calling dispatch on 0x56216e9afd40
-486> 2019-07-17 17:52:28.962 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).handle_write
-486> 2019-07-17 17:52:28.962 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).prepare_send_message m auth(proto 2 32 bytes epoch 0) v1
-486> 2019-07-17 17:52:28.962 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).prepare_send_message encoding features 4611087854031667195 0x56216e9af200 auth(proto 2 32 bytes epoch 0) v1
-486> 2019-07-17 17:52:28.962 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).write_message no session security
-486> 2019-07-17 17:52:28.962 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).write_message sending message type=17 src client.? front=62 data=0 off 0
-486> 2019-07-17 17:52:28.962 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).write_message sending 2 0x56216e9af200
-486> 2019-07-17 17:52:28.962 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1)._try_send sent bytes 137 remaining bytes 0
-486> 2019-07-17 17:52:28.962 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).write_message sending 0x56216e9af200 done.
-486> 2019-07-17 17:52:28.962 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).process prev state is STATE_OPEN
-486> 2019-07-17 17:52:28.962 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process prev state is STATE_OPEN
-486> 2019-07-17 17:52:28.962 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process begin MSG
-486> 2019-07-17 17:52:28.962 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process got MSG header
-486> 2019-07-17 17:52:28.962 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process got envelope type=18 src mon.0 front=206 data=0 off 0
-486> 2019-07-17 17:52:28.962 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_THROTTLE_MESSAGE pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_HEADER
-486> 2019-07-17 17:52:28.962 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_THROTTLE_BYTES pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_THROTTLE_MESSAGE
-486> 2019-07-17 17:52:28.962 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_THROTTLE_DISPATCH_QUEUE pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_THROTTLE_BYTES
-486> 2019-07-17 17:52:28.962 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FRONT pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_THROTTLE_DISPATCH_QUEUE
-486> 2019-07-17 17:52:28.962 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FRONT pgs=332 cs=1 l=1).process got front 206
-486> 2019-07-17 17:52:28.962 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1).process aborted = 0
-486> 2019-07-17 17:52:28.962 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1).process got 206 + 0 + 0 byte message
-486> 2019-07-17 17:52:28.962 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1).process no session security set
-486> 2019-07-17 17:52:28.962 7f510e118700 5 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1). rx mon.0 seq 3 0x56216e9af200 auth_reply(proto 2 0 (0) Success) v1
-486> 2019-07-17 17:52:28.962 7f510e118700 20 -- 129.13.170.240:0/1461896717 queue 0x56216e9af200 prio 196
-486> 2019-07-17 17:52:28.962 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_READ_FRONT
-486> 2019-07-17 17:52:28.962 7f510d116700 1 -- 129.13.170.240:0/1461896717 <== mon.0 129.13.170.240:6789/0 3 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 206+0+0 (528335564 0 0) 0x56216e9af200 con 0x56216ea18c00
-486> 2019-07-17 17:52:28.962 7f510d116700 1 monclient: found mon.mon01
-486> 2019-07-17 17:52:28.963 7f510d116700 10 monclient: _send_mon_message to mon.mon01 at 129.13.170.240:6789/0
-486> 2019-07-17 17:52:28.963 7f510d116700 1 -- 129.13.170.240:0/1461896717 --> 129.13.170.240:6789/0 -- mon_subscribe({config=0+,monmap=0+}) v3 -- 0x56216e9c7c00 con 0
-486> 2019-07-17 17:52:28.963 7f510d116700 15 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).send_message inline write is denied, reschedule m=0x56216e9c7c00
-486> 2019-07-17 17:52:28.963 7f510d116700 20 Event(0x56216ed11480 nevent=5000 time_id=2).wakeup
-486> 2019-07-17 17:52:28.963 7f510d116700 10 monclient: _check_auth_rotating renewing rotating keys (they expired before 2019-07-17 17:51:58.963637)
-486> 2019-07-17 17:52:28.963 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).handle_write
-486> 2019-07-17 17:52:28.963 7f510d116700 10 monclient: _send_mon_message to mon.mon01 at 129.13.170.240:6789/0
-486> 2019-07-17 17:52:28.963 7f510d116700 1 -- 129.13.170.240:0/1461896717 --> 129.13.170.240:6789/0 -- auth(proto 2 2 bytes epoch 0) v1 -- 0x56216e9afd40 con 0
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).prepare_send_message m mon_subscribe({config=0+,monmap=0+}) v3
-486> 2019-07-17 17:52:28.963 7f510d116700 15 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).send_message inline write is denied, reschedule m=0x56216e9afd40
-486> 2019-07-17 17:52:28.963 7f510d116700 20 Event(0x56216ed11480 nevent=5000 time_id=2).wakeup
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).prepare_send_message encoding features 4611087854031667195 0x56216e9c7c00 mon_subscribe({config=0+,monmap=0+}) v3
-486> 2019-07-17 17:52:28.963 7f510d116700 10 -- 129.13.170.240:0/1461896717 dispatch_throttle_release 206 to dispatch throttler 206/104857600
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).write_message no session security
-486> 2019-07-17 17:52:28.963 7f510d116700 20 -- 129.13.170.240:0/1461896717 done calling dispatch on 0x56216e9af200
-486> 2019-07-17 17:52:28.963 7f511ec32d80 5 monclient: authenticate success, global_id 4204427
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).write_message sending message type=15 src client.? front=54 data=0 off 0
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).write_message sending 3 0x56216e9c7c00
-486> 2019-07-17 17:52:28.963 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1)._try_send sent bytes 129 remaining bytes 0
-486> 2019-07-17 17:52:28.963 7f510e118700 20 Event(0x56216ed11480 nevent=5000 time_id=2).create_file_event create event started fd=13 mask=2 original mask is 1
-486> 2019-07-17 17:52:28.963 7f510e118700 20 EpollDriver.add_event add event fd=13 cur_mask=1 add_mask=2 to 7
-486> 2019-07-17 17:52:28.963 7f510e118700 20 Event(0x56216ed11480 nevent=5000 time_id=2).create_file_event create event end fd=13 mask=2 original mask is 3
-486> 2019-07-17 17:52:28.963 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).write_message sending 0x56216e9c7c00 done.
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).prepare_send_message m auth(proto 2 2 bytes epoch 0) v1
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).prepare_send_message encoding features 4611087854031667195 0x56216e9afd40 auth(proto 2 2 bytes epoch 0) v1
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).write_message no session security
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).write_message sending message type=17 src client.? front=32 data=0 off 0
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).write_message sending 4 0x56216e9afd40
-486> 2019-07-17 17:52:28.963 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1)._try_send sent bytes 107 remaining bytes 0
-486> 2019-07-17 17:52:28.963 7f510e118700 20 EpollDriver.del_event del event fd=13 cur_mask=3 delmask=2 to 7
-486> 2019-07-17 17:52:28.963 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).write_message sending 0x56216e9afd40 done.
-486> 2019-07-17 17:52:28.963 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).handle_write
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).process prev state is STATE_OPEN
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process prev state is STATE_OPEN
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process begin MSG
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process got MSG header
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process got envelope type=62 src mon.0 front=4 data=0 off 0
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_THROTTLE_MESSAGE pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_HEADER
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_THROTTLE_BYTES pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_THROTTLE_MESSAGE
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_THROTTLE_DISPATCH_QUEUE pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_THROTTLE_BYTES
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FRONT pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_THROTTLE_DISPATCH_QUEUE
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FRONT pgs=332 cs=1 l=1).process got front 4
-486> 2019-07-17 17:52:28.963 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1).process aborted = 0
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1).process got 4 + 0 + 0 byte message
-486> 2019-07-17 17:52:28.963 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1).process no session security set
-486> 2019-07-17 17:52:28.963 7f510e118700 5 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1). rx mon.0 seq 4 0x56216ede8000 config(0 keys) v1
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 queue 0x56216ede8000 prio 196
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_READ_FRONT
-486> 2019-07-17 17:52:28.963 7f510d116700 1 -- 129.13.170.240:0/1461896717 <== mon.0 129.13.170.240:6789/0 4 ==== config(0 keys) v1 ==== 4+0+0 (0 0 0) 0x56216ede8000 con 0x56216ea18c00
-486> 2019-07-17 17:52:28.963 7f510d116700 10 monclient: handle_config config(0 keys) v1
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process prev state is STATE_OPEN
-486> 2019-07-17 17:52:28.963 7f510d116700 10 -- 129.13.170.240:0/1461896717 dispatch_throttle_release 4 to dispatch throttler 4/104857600
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process begin MSG
-486> 2019-07-17 17:52:28.963 7f511ec32d80 10 monclient: get_monmap_and_config success
-486> 2019-07-17 17:52:28.963 7f510d116700 20 -- 129.13.170.240:0/1461896717 done calling dispatch on 0x56216ede8000
-486> 2019-07-17 17:52:28.963 7f511ec32d80 10 monclient: shutdown
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process got MSG header
-486> 2019-07-17 17:52:28.963 7f511ec32d80 1 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).mark_down
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process got envelope type=4 src mon.0 front=187 data=0 off 0
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_THROTTLE_MESSAGE pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_HEADER
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_THROTTLE_BYTES pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_THROTTLE_MESSAGE
-486> 2019-07-17 17:52:28.963 7f510b913700 4 set_mon_vals no callback set
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_THROTTLE_DISPATCH_QUEUE pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_THROTTLE_BYTES
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FRONT pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_THROTTLE_DISPATCH_QUEUE
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FRONT pgs=332 cs=1 l=1).process got front 187
-486> 2019-07-17 17:52:28.963 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1).process aborted = 0
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1).process got 187 + 0 + 0 byte message
-486> 2019-07-17 17:52:28.963 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1).process no session security set
-486> 2019-07-17 17:52:28.963 7f510e118700 5 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1). rx mon.0 seq 5 0x56216e9afd40 mon_map magic: 0 v1
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 queue 0x56216e9afd40 prio 196
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_READ_FRONT
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process prev state is STATE_OPEN
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process begin MSG
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process got MSG header
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_HEADER pgs=332 cs=1 l=1).process got envelope type=18 src mon.0 front=194 data=0 off 0
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_THROTTLE_MESSAGE pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_HEADER
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_THROTTLE_BYTES pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_THROTTLE_MESSAGE
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_THROTTLE_DISPATCH_QUEUE pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_THROTTLE_BYTES
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FRONT pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_THROTTLE_DISPATCH_QUEUE
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FRONT pgs=332 cs=1 l=1).process got front 194
-486> 2019-07-17 17:52:28.963 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1).process aborted = 0
-486> 2019-07-17 17:52:28.963 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1).process got 194 + 0 + 0 byte message
-486> 2019-07-17 17:52:28.963 7f510e118700 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1).process no session security set
-486> 2019-07-17 17:52:28.963 7f510e118700 5 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=332 cs=1 l=1). rx mon.0 seq 6 0x56216edf4000 auth_reply(proto 2 0 (0) Success) v1
-486> 2019-07-17 17:52:28.964 7f510e118700 20 -- 129.13.170.240:0/1461896717 queue 0x56216edf4000 prio 196
-486> 2019-07-17 17:52:28.964 7f510e118700 20 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).process prev state is STATE_OPEN_MESSAGE_READ_FRONT
-486> 2019-07-17 17:52:28.964 7f511ec32d80 2 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1)._stop
-486> 2019-07-17 17:52:28.964 7f511ec32d80 10 -- 129.13.170.240:0/1461896717 dispatch_throttle_release 187 to dispatch throttler 381/104857600
-486> 2019-07-17 17:52:28.964 7f511ec32d80 10 -- 129.13.170.240:0/1461896717 dispatch_throttle_release 194 to dispatch throttler 194/104857600
-486> 2019-07-17 17:52:28.964 7f511ec32d80 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:6789/0 conn(0x56216ea18c00 :-1 s=STATE_OPEN pgs=332 cs=1 l=1).discard_out_queue started
-486> 2019-07-17 17:52:28.964 7f511ec32d80 20 Event(0x56216ed11480 nevent=5000 time_id=2).wakeup
-486> 2019-07-17 17:52:28.964 7f510e118700 20 EpollDriver.del_event del event fd=13 cur_mask=1 delmask=3 to 7
-486> 2019-07-17 17:52:28.965 7f511ec32d80 10 -- 129.13.170.240:0/1461896717 shutdown 129.13.170.240:0/1461896717
-486> 2019-07-17 17:52:28.965 7f511ec32d80 10 Processor -- stop
-486> 2019-07-17 17:52:28.965 7f511ec32d80 1 -- 129.13.170.240:0/1461896717 shutdown_connections
-486> 2019-07-17 17:52:28.965 7f511ec32d80 5 -- 129.13.170.240:0/1461896717 shutdown_connections mark down 129.13.170.240:6789/0 0x56216ea18c00
-486> 2019-07-17 17:52:28.965 7f511ec32d80 5 -- 129.13.170.240:0/1461896717 shutdown_connections delete 0x56216ea18c00
-486> 2019-07-17 17:52:28.965 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:28.965 7f511ec32d80 20 Event(0x56216ed11480 nevent=5000 time_id=2).wakeup
-486> 2019-07-17 17:52:28.965 7f511ec32d80 20 Event(0x56216ed11880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:28.965 7f511ec32d80 10 -- 129.13.170.240:0/1461896717 wait: waiting for dispatch queue
-486> 2019-07-17 17:52:28.966 7f511ec32d80 10 -- 129.13.170.240:0/1461896717 wait: dispatch queue is stopped
-486> 2019-07-17 17:52:28.966 7f511ec32d80 1 -- 129.13.170.240:0/1461896717 shutdown_connections
-486> 2019-07-17 17:52:28.966 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:28.966 7f511ec32d80 20 Event(0x56216ed11480 nevent=5000 time_id=2).wakeup
-486> 2019-07-17 17:52:28.966 7f511ec32d80 20 Event(0x56216ed11880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:28.966 7f511ec32d80 10 -- 129.13.170.240:0/1461896717 wait: done.
-486> 2019-07-17 17:52:28.966 7f511ec32d80 1 -- 129.13.170.240:0/1461896717 wait complete.
-486> 2019-07-17 17:52:28.966 7f511ec32d80 1 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:0/1461896717 conn(0x56216ea18000 :-1 s=STATE_NONE pgs=0 cs=0 l=0).mark_down
-486> 2019-07-17 17:52:28.966 7f511ec32d80 2 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:0/1461896717 conn(0x56216ea18000 :-1 s=STATE_NONE pgs=0 cs=0 l=0)._stop
-486> 2019-07-17 17:52:28.966 7f511ec32d80 10 -- 129.13.170.240:0/1461896717 >> 129.13.170.240:0/1461896717 conn(0x56216ea18000 :-1 s=STATE_NONE pgs=0 cs=0 l=0).discard_out_queue started
-486> 2019-07-17 17:52:28.966 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:28.968 7f511ec32d80 0 set uid:gid to 167:167 (ceph:ceph)
-486> 2019-07-17 17:52:28.968 7f511ec32d80 0 ceph version 13.2.6 (7b695f835b03642f85998b2ae7b6dd093d9fbce4) mimic (stable), process ceph-osd, pid 34415
-486> 2019-07-17 17:52:28.968 7f511ec32d80 0 pidfile_write: ignore empty --pid-file
-486> 2019-07-17 17:52:29.005 7f511ec32d80 5 asok(0x56216e9de5a0) init /var/run/ceph/ceph-osd.0.asok
-486> 2019-07-17 17:52:29.005 7f511ec32d80 5 asok(0x56216e9de5a0) bind_and_listen /var/run/ceph/ceph-osd.0.asok
-486> 2019-07-17 17:52:29.005 7f511ec32d80 5 asok(0x56216e9de5a0) register_command 0 hook 0x56216e9b3490
-486> 2019-07-17 17:52:29.005 7f511ec32d80 5 asok(0x56216e9de5a0) register_command version hook 0x56216e9b3490
-486> 2019-07-17 17:52:29.005 7f511ec32d80 5 asok(0x56216e9de5a0) register_command git_version hook 0x56216e9b3490
-486> 2019-07-17 17:52:29.005 7f511ec32d80 5 asok(0x56216e9de5a0) register_command help hook 0x56216e9b4500
-486> 2019-07-17 17:52:29.005 7f511ec32d80 5 asok(0x56216e9de5a0) register_command get_command_descriptions hook 0x56216e9b4570
-486> 2019-07-17 17:52:29.005 7f510c915700 5 asok(0x56216e9de5a0) entry start
-486> 2019-07-17 17:52:29.005 7f511ec32d80 5 object store type is bluestore
-486> 2019-07-17 17:52:29.005 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0) set_cache_shards 1
-486> 2019-07-17 17:52:29.005 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0/block) _read_bdev_label
-486> 2019-07-17 17:52:29.006 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0/block) _read_bdev_label got bdev(osd_uuid 38389b5e-2af7-47c0-8505-fd658519cb92, size 0x74702400000, btime 2018-05-28 22:43:46.113504, desc main, 8 meta)
-486> 2019-07-17 17:52:29.006 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0/block) _read_bdev_label
-486> 2019-07-17 17:52:29.006 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0/block) _read_bdev_label got bdev(osd_uuid 38389b5e-2af7-47c0-8505-fd658519cb92, size 0x74702400000, btime 2018-05-28 22:43:46.113504, desc main, 8 meta)
-486> 2019-07-17 17:52:29.006 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0/block) _read_bdev_label
-486> 2019-07-17 17:52:29.007 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0/block) _read_bdev_label got bdev(osd_uuid 38389b5e-2af7-47c0-8505-fd658519cb92, size 0x74702400000, btime 2018-05-28 22:43:46.113504, desc main, 8 meta)
-486> 2019-07-17 17:52:29.007 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0/block) _read_bdev_label
-486> 2019-07-17 17:52:29.007 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0/block) _read_bdev_label got bdev(osd_uuid 38389b5e-2af7-47c0-8505-fd658519cb92, size 0x74702400000, btime 2018-05-28 22:43:46.113504, desc main, 8 meta)
-486> 2019-07-17 17:52:29.009 7f511ec32d80 -1 Public network was set, but cluster network was not set
-486> 2019-07-17 17:52:29.009 7f511ec32d80 -1 Using public network also for cluster network
-486> 2019-07-17 17:52:29.010 7f511ec32d80 10 -- - bind bind 129.13.170.240:0/0
-486> 2019-07-17 17:52:29.010 7f511ec32d80 10 Processor -- bind
-486> 2019-07-17 17:52:29.010 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.010 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6800: (98) Address already in use
-486> 2019-07-17 17:52:29.010 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.010 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6801: (98) Address already in use
-486> 2019-07-17 17:52:29.010 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.010 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6802: (98) Address already in use
-486> 2019-07-17 17:52:29.010 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.010 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6803: (98) Address already in use
-486> 2019-07-17 17:52:29.010 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.010 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6804: (98) Address already in use
-486> 2019-07-17 17:52:29.010 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.010 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6805: (98) Address already in use
-486> 2019-07-17 17:52:29.010 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.010 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6806: (98) Address already in use
-486> 2019-07-17 17:52:29.010 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.010 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6807: (98) Address already in use
-486> 2019-07-17 17:52:29.010 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.010 7f511ec32d80 10 Processor -- bind bound on random port 129.13.170.240:6808/0
-486> 2019-07-17 17:52:29.010 7f511ec32d80 10 Processor -- bind bound to 129.13.170.240:6808/0
-486> 2019-07-17 17:52:29.010 7f511ec32d80 1 -- 129.13.170.240:0/0 learned_addr learned my addr 129.13.170.240:0/0
-486> 2019-07-17 17:52:29.010 7f511ec32d80 1 -- 129.13.170.240:6808/34415 _finish_bind bind my_inst.addr is 129.13.170.240:6808/34415
-486> 2019-07-17 17:52:29.010 7f511ec32d80 10 -- - bind bind 129.13.170.240:0/0
-486> 2019-07-17 17:52:29.010 7f511ec32d80 10 Processor -- bind
-486> 2019-07-17 17:52:29.010 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.011 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6800: (98) Address already in use
-486> 2019-07-17 17:52:29.011 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.011 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6801: (98) Address already in use
-486> 2019-07-17 17:52:29.011 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.011 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6802: (98) Address already in use
-486> 2019-07-17 17:52:29.011 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.011 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6803: (98) Address already in use
-486> 2019-07-17 17:52:29.011 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.011 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6804: (98) Address already in use
-486> 2019-07-17 17:52:29.011 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.011 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6805: (98) Address already in use
-486> 2019-07-17 17:52:29.011 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.011 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6806: (98) Address already in use
-486> 2019-07-17 17:52:29.011 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.011 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6807: (98) Address already in use
-486> 2019-07-17 17:52:29.011 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.011 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6808: (98) Address already in use
-486> 2019-07-17 17:52:29.011 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.011 7f511ec32d80 10 Processor -- bind bound on random port 129.13.170.240:6809/0
-486> 2019-07-17 17:52:29.011 7f511ec32d80 10 Processor -- bind bound to 129.13.170.240:6809/0
-486> 2019-07-17 17:52:29.011 7f511ec32d80 1 -- 129.13.170.240:0/0 learned_addr learned my addr 129.13.170.240:0/0
-486> 2019-07-17 17:52:29.011 7f511ec32d80 1 -- 129.13.170.240:6809/34415 _finish_bind bind my_inst.addr is 129.13.170.240:6809/34415
-486> 2019-07-17 17:52:29.011 7f511ec32d80 10 -- - bind bind 129.13.170.240:0/0
-486> 2019-07-17 17:52:29.011 7f511ec32d80 10 Processor -- bind
-486> 2019-07-17 17:52:29.011 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.011 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6800: (98) Address already in use
-486> 2019-07-17 17:52:29.011 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.011 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6801: (98) Address already in use
-486> 2019-07-17 17:52:29.011 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.011 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6802: (98) Address already in use
-486> 2019-07-17 17:52:29.011 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.011 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6803: (98) Address already in use
-486> 2019-07-17 17:52:29.011 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.011 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6804: (98) Address already in use
-486> 2019-07-17 17:52:29.011 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.011 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6805: (98) Address already in use
-486> 2019-07-17 17:52:29.011 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.011 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6806: (98) Address already in use
-486> 2019-07-17 17:52:29.011 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.012 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6807: (98) Address already in use
-486> 2019-07-17 17:52:29.012 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.012 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6808: (98) Address already in use
-486> 2019-07-17 17:52:29.012 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.012 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6809: (98) Address already in use
-486> 2019-07-17 17:52:29.012 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.012 7f511ec32d80 10 Processor -- bind bound on random port 129.13.170.240:6810/0
-486> 2019-07-17 17:52:29.012 7f511ec32d80 10 Processor -- bind bound to 129.13.170.240:6810/0
-486> 2019-07-17 17:52:29.012 7f511ec32d80 1 -- 129.13.170.240:0/0 learned_addr learned my addr 129.13.170.240:0/0
-486> 2019-07-17 17:52:29.012 7f511ec32d80 1 -- 129.13.170.240:6810/34415 _finish_bind bind my_inst.addr is 129.13.170.240:6810/34415
-486> 2019-07-17 17:52:29.012 7f511ec32d80 10 -- - bind bind 129.13.170.240:0/0
-486> 2019-07-17 17:52:29.012 7f511ec32d80 10 Processor -- bind
-486> 2019-07-17 17:52:29.012 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.012 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6800: (98) Address already in use
-486> 2019-07-17 17:52:29.012 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.012 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6801: (98) Address already in use
-486> 2019-07-17 17:52:29.012 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.012 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6802: (98) Address already in use
-486> 2019-07-17 17:52:29.012 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.012 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6803: (98) Address already in use
-486> 2019-07-17 17:52:29.012 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.012 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6804: (98) Address already in use
-486> 2019-07-17 17:52:29.012 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.012 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6805: (98) Address already in use
-486> 2019-07-17 17:52:29.012 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.012 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6806: (98) Address already in use
-486> 2019-07-17 17:52:29.012 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.012 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6807: (98) Address already in use
-486> 2019-07-17 17:52:29.012 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.012 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6808: (98) Address already in use
-486> 2019-07-17 17:52:29.012 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.012 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6809: (98) Address already in use
-486> 2019-07-17 17:52:29.012 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.012 7f510e919700 10 PosixStack listen unable to bind to 129.13.170.240:6810: (98) Address already in use
-486> 2019-07-17 17:52:29.012 7f511ec32d80 20 Event(0x56216ed10880 nevent=5000 time_id=1).wakeup
-486> 2019-07-17 17:52:29.012 7f511ec32d80 10 Processor -- bind bound on random port 129.13.170.240:6811/0
-486> 2019-07-17 17:52:29.012 7f511ec32d80 10 Processor -- bind bound to 129.13.170.240:6811/0
-486> 2019-07-17 17:52:29.012 7f511ec32d80 1 -- 129.13.170.240:0/0 learned_addr learned my addr 129.13.170.240:0/0
-486> 2019-07-17 17:52:29.012 7f511ec32d80 1 -- 129.13.170.240:6811/34415 _finish_bind bind my_inst.addr is 129.13.170.240:6811/34415
-486> 2019-07-17 17:52:29.013 7f511ec32d80 10 monclient: build_initial_monmap
-486> 2019-07-17 17:52:29.022 7f511ec32d80 0 load: jerasure load: lrc load: isa
-486> 2019-07-17 17:52:29.022 7f511ec32d80 5 adding auth protocol: cephx
-486> 2019-07-17 17:52:29.022 7f511ec32d80 5 adding auth protocol: cephx
-486> 2019-07-17 17:52:29.022 7f511ec32d80 1 bdev create path /var/lib/ceph/osd/ceph-0/block type kernel
-486> 2019-07-17 17:52:29.022 7f511ec32d80 1 bdev(0x56216ed56000 /var/lib/ceph/osd/ceph-0/block) open path /var/lib/ceph/osd/ceph-0/block
-486> 2019-07-17 17:52:29.022 7f511ec32d80 1 bdev(0x56216ed56000 /var/lib/ceph/osd/ceph-0/block) open size 8001561821184 (0x74702400000, 7.3 TiB) block_size 4096 (4 KiB) rotational
-486> 2019-07-17 17:52:29.023 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0/block) _read_bdev_label
-486> 2019-07-17 17:52:29.023 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0/block) _read_bdev_label got bdev(osd_uuid 38389b5e-2af7-47c0-8505-fd658519cb92, size 0x74702400000, btime 2018-05-28 22:43:46.113504, desc main, 8 meta)
-486> 2019-07-17 17:52:29.023 7f511ec32d80 1 bluestore(/var/lib/ceph/osd/ceph-0) _set_cache_sizes cache_size 1073741824 meta 0.4 kv 0.4 data 0.2
-486> 2019-07-17 17:52:29.023 7f511ec32d80 1 bdev(0x56216ed56000 /var/lib/ceph/osd/ceph-0/block) close
-486> 2019-07-17 17:52:29.281 7f511ec32d80 5 asok(0x56216e9de5a0) register_command objecter_requests hook 0x56216e9b47d0
-486> 2019-07-17 17:52:29.281 7f511ec32d80 1 -- 129.13.170.240:6808/34415 start start
-486> 2019-07-17 17:52:29.281 7f511ec32d80 1 -- - start start
-486> 2019-07-17 17:52:29.281 7f511ec32d80 1 -- - start start
-486> 2019-07-17 17:52:29.281 7f511ec32d80 1 -- 129.13.170.240:6811/34415 start start
-486> 2019-07-17 17:52:29.281 7f511ec32d80 1 -- 129.13.170.240:6810/34415 start start
-486> 2019-07-17 17:52:29.281 7f511ec32d80 1 -- 129.13.170.240:6809/34415 start start
-486> 2019-07-17 17:52:29.281 7f511ec32d80 1 -- - start start
-486> 2019-07-17 17:52:29.281 7f511ec32d80 2 osd.0 0 init /var/lib/ceph/osd/ceph-0 (looks like hdd)
-486> 2019-07-17 17:52:29.281 7f511ec32d80 2 osd.0 0 journal /var/lib/ceph/osd/ceph-0/journal
-486> 2019-07-17 17:52:29.281 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0) set_cache_shards 5
-486> 2019-07-17 17:52:29.281 7f511ec32d80 1 bluestore(/var/lib/ceph/osd/ceph-0) _mount path /var/lib/ceph/osd/ceph-0
-486> 2019-07-17 17:52:29.281 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0/block) _read_bdev_label
-486> 2019-07-17 17:52:29.282 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0/block) _read_bdev_label got bdev(osd_uuid 38389b5e-2af7-47c0-8505-fd658519cb92, size 0x74702400000, btime 2018-05-28 22:43:46.113504, desc main, 8 meta)
-486> 2019-07-17 17:52:29.282 7f511ec32d80 1 bdev create path /var/lib/ceph/osd/ceph-0/block type kernel
-486> 2019-07-17 17:52:29.282 7f511ec32d80 1 bdev(0x56216ed56000 /var/lib/ceph/osd/ceph-0/block) open path /var/lib/ceph/osd/ceph-0/block
-486> 2019-07-17 17:52:29.282 7f511ec32d80 1 bdev(0x56216ed56000 /var/lib/ceph/osd/ceph-0/block) open size 8001561821184 (0x74702400000, 7.3 TiB) block_size 4096 (4 KiB) rotational
-486> 2019-07-17 17:52:29.282 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0/block) _read_bdev_label
-486> 2019-07-17 17:52:29.287 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0/block) _read_bdev_label got bdev(osd_uuid 38389b5e-2af7-47c0-8505-fd658519cb92, size 0x74702400000, btime 2018-05-28 22:43:46.113504, desc main, 8 meta)
-486> 2019-07-17 17:52:29.287 7f511ec32d80 1 bluestore(/var/lib/ceph/osd/ceph-0) _set_cache_sizes cache_size 1073741824 meta 0.4 kv 0.4 data 0.2
-486> 2019-07-17 17:52:29.287 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0/block) _read_bdev_label
-486> 2019-07-17 17:52:29.287 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0/block) _read_bdev_label got bdev(osd_uuid 38389b5e-2af7-47c0-8505-fd658519cb92, size 0x74702400000, btime 2018-05-28 22:43:46.113504, desc main, 8 meta)
-486> 2019-07-17 17:52:29.287 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0) _open_db kv_backend = rocksdb
-486> 2019-07-17 17:52:29.287 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0/block) _read_bdev_label
-486> 2019-07-17 17:52:29.287 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0/block) _read_bdev_label got bdev(osd_uuid 38389b5e-2af7-47c0-8505-fd658519cb92, size 0x74702400000, btime 2018-05-28 22:43:46.113504, desc main, 8 meta)
-486> 2019-07-17 17:52:29.287 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0) _open_db do_bluefs = 1
-486> 2019-07-17 17:52:29.287 7f511ec32d80 10 bluestore(/var/lib/ceph/osd/ceph-0) _open_db initializing bluefs
-486> 2019-07-17 17:52:29.287 7f511ec32d80 10 bluefs add_block_device bdev 1 path /var/lib/ceph/osd/ceph-0/block
-486> 2019-07-17 17:52:29.287 7f511ec32d80 1 bdev create path /var/lib/ceph/osd/ceph-0/block type kernel
-486> 2019-07-17 17:52:29.287 7f511ec32d80 1 bdev(0x56216ed56a80 /var/lib/ceph/osd/ceph-0/block) open path /var/lib/ceph/osd/ceph-0/block
-486> 2019-07-17 17:52:29.288 7f511ec32d80 1 bdev(0x56216ed56a80 /var/lib/ceph/osd/ceph-0/block) open size 8001561821184 (0x74702400000, 7.3 TiB) block_size 4096 (4 KiB) rotational
-486> 2019-07-17 17:52:29.288 7f511ec32d80 1 bluefs add_block_device bdev 1 path /var/lib/ceph/osd/ceph-0/block size 7.3 TiB
-486> 2019-07-17 17:52:29.288 7f511ec32d80 1 bluefs mount
-486> 2019-07-17 17:52:29.288 7f511ec32d80 10 bluefs _open_super
-486> 2019-07-17 17:52:29.288 7f511ec32d80 10 bluefs _open_super superblock 50
-486> 2019-07-17 17:52:29.288 7f511ec32d80 10 bluefs _open_super log_fnode file(ino 1 size 0x100000 mtime 0.000000 bdev 0 allocated 500000 extents [1:0x38422c00000+100000,1:0x38422800000+400000])
-486> 2019-07-17 17:52:29.288 7f511ec32d80 20 bluefs _init_alloc
-486> 2019-07-17 17:52:29.288 7f511ec32d80 10 bluefs _replay
-486> 2019-07-17 17:52:29.288 7f511ec32d80 10 bluefs _replay log_fnode file(ino 1 size 0x100000 mtime 0.000000 bdev 0 allocated 500000 extents [1:0x38422c00000+100000,1:0x38422800000+400000])
-486> 2019-07-17 17:52:29.288 7f511ec32d80 10 bluefs _read h 0x56216edff500 0x0~1000 from file(ino 1 size 0x100000 mtime 0.000000 bdev 0 allocated 500000 extents [1:0x38422c00000+100000,1:0x38422800000+400000])
-486> 2019-07-17 17:52:29.288 7f511ec32d80 20 bluefs _read fetching 0x0~100000 of 1:0x38422c00000+100000
-486> 2019-07-17 17:52:29.294 7f511ec32d80 20 bluefs _read left 0x100000 len 0x1000
-486> 2019-07-17 17:52:29.294 7f511ec32d80 20 bluefs _read got 4096
-486> 2019-07-17 17:52:29.294 7f511ec32d80 10 bluefs _replay 0x0: stop: uuid 00000000-0000-0000-0000-000000000000 != super.uuid fde67a0e-ddf7-4928-bc1d-873e985ec3a2
-486> 2019-07-17 17:52:29.294 7f511ec32d80 10 bluefs _replay log file size was 0x100000
-486> 2019-07-17 17:52:29.294 7f511ec32d80 10 bluefs _replay done
-486> 2019-07-17 17:52:29.294 7f511ec32d80 10 stupidalloc 0x0x56216ecff680 init_rm_free 0x38422c00000~100000
-486> 2019-07-17 17:52:29.298 7f511ec32d80 -1 /home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/13.2.6/rpm/el7/BUILD/ceph-13.2.6/src/os/bluestore/StupidAllocator.cc: In function 'virtual void StupidAllocator::init_rm_free(uint64_t, uint64_t)' thread 7f511ec32d80 time 2019-07-17 17:52:29.295172
/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/13.2.6/rpm/el7/BUILD/ceph-13.2.6/src/os/bluestore/StupidAllocator.cc: 336: FAILED assert(rm.empty())

ceph version 13.2.6 (7b695f835b03642f85998b2ae7b6dd093d9fbce4) mimic (stable)
1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x14b) [0x7f511601736b]
2: (()+0x26e4f7) [0x7f51160174f7]
3: (StupidAllocator::init_rm_free(unsigned long, unsigned long)+0x1fb6) [0x56216c2aac46]
4: (BlueFS::mount()+0x260) [0x56216c28fd60]
5: (BlueStore::_open_db(bool, bool)+0x170f) [0x56216c1b193f]
6: (BlueStore::_mount(bool, bool)+0x4d1) [0x56216c1e2071]
7: (OSD::init()+0x28f) [0x56216bd89edf]
8: (main()+0x23a3) [0x56216bc687a3]
9: (__libc_start_main()+0xf5) [0x7f5111b973d5]
10: (()+0x385900) [0x56216bd40900]

-486> 2019-07-17 17:52:29.302 7f511ec32d80 -1 *** Caught signal (Aborted) **
in thread 7f511ec32d80 thread_name:ceph-osd

ceph version 13.2.6 (7b695f835b03642f85998b2ae7b6dd093d9fbce4) mimic (stable)
1: (()+0xf5d0) [0x7f5112b8a5d0]
2: (gsignal()+0x37) [0x7f5111bab207]
3: (abort()+0x148) [0x7f5111bac8f8]
4: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x248) [0x7f5116017468]
5: (()+0x26e4f7) [0x7f51160174f7]
6: (StupidAllocator::init_rm_free(unsigned long, unsigned long)+0x1fb6) [0x56216c2aac46]
7: (BlueFS::mount()+0x260) [0x56216c28fd60]
8: (BlueStore::_open_db(bool, bool)+0x170f) [0x56216c1b193f]
9: (BlueStore::_mount(bool, bool)+0x4d1) [0x56216c1e2071]
10: (OSD::init()+0x28f) [0x56216bd89edf]
11: (main()+0x23a3) [0x56216bc687a3]
12: (__libc_start_main()+0xf5) [0x7f5111b973d5]
13: (()+0x385900) [0x56216bd40900]
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
20/20 osd
0/ 5 optracker
0/ 5 objclass
1/ 3 filestore
1/ 3 journal
20/20 ms
1/ 5 mon
0/10 monc
1/ 5 paxos
0/ 5 tp
1/ 5 auth
1/ 5 crypto
1/ 1 finisher
1/ 1 reserver
1/ 5 heartbeatmap
1/ 5 perfcounter
1/ 5 rgw
1/ 5 rgw_sync
1/10 civetweb
1/ 5 javaclient
1/ 5 asok
1/ 1 throttle
0/ 0 refs
1/ 5 xio
1/ 5 compressor
20/20 bluestore
20/20 bluefs
1/ 3 bdev
1/ 5 kstore
4/ 5 rocksdb
4/ 5 leveldb
4/ 5 memdb
1/ 5 kinetic
1/ 5 fuse
1/ 5 mgr
1/ 5 mgrc
1/ 5 dpdk
1/ 5 eventtrace
-2/-2 (syslog threshold)
99/99 (stderr threshold)
max_recent 10000
max_new 1000
log_file /var/lib/ceph/crash/2019-07-17_15:52:29.302939Z_6ad992ef-39cc-4303-b69b-ee570ece8625/log
--- end dump of recent events ---
(3-3/3)