Project

General

Profile

Support #38374 » mds-crash.log

Jérôme Poulin, 02/19/2019 02:33 AM

 
sudo ./bin/ceph-mds --setuser ceph --setgroup ceph --cluster ti -i sg1vosrv12 -d
2019-02-18 21:26:09.377 7ff439f23440 0 set uid:gid to 64045:64045 (ceph:ceph)
2019-02-18 21:26:09.377 7ff439f23440 0 ceph version 13.2.4 (b10be4d44915a4d78a8e06aa31919e74927b142e) mimic (stable), process ceph-mds, pid 32244
2019-02-18 21:26:09.377 7ff439f23440 0 pidfile_write: ignore empty --pid-file
starting mds.sg1vosrv12 at -
2019-02-18 21:26:09.405 7ff429169700 1 mds.sg1vosrv12 Updating MDS map to version 305 from mon.1
2019-02-18 21:26:13.525 7ff429169700 1 mds.sg1vosrv12 Updating MDS map to version 306 from mon.1
2019-02-18 21:26:13.525 7ff429169700 1 mds.sg1vosrv12 Map has assigned me to become a standby
2019-02-18 21:26:13.557 7ff429169700 1 mds.sg1vosrv12 Updating MDS map to version 307 from mon.1
2019-02-18 21:26:13.557 7ff429169700 1 mds.0.307 handle_mds_map i am now mds.0.307
2019-02-18 21:26:13.557 7ff429169700 1 mds.0.307 handle_mds_map state change up:boot --> up:replay
2019-02-18 21:26:13.557 7ff429169700 1 mds.0.307 replay_start
2019-02-18 21:26:13.557 7ff429169700 1 mds.0.307 recovery set is
2019-02-18 21:26:13.557 7ff429169700 1 mds.0.307 waiting for osdmap 87591 (which blacklists prior instance)
2019-02-18 21:26:13.569 7ff422774700 0 mds.0.cache creating system inode with ino:0x100
2019-02-18 21:26:13.569 7ff422774700 0 mds.0.cache creating system inode with ino:0x1
2019-02-18 21:26:15.101 7ff420f71700 0 log_channel(cluster) log [WRN] : replayed op client.18359173:903,900 used ino 0x100000051bd but session next is 0x10000004bde
2019-02-18 21:26:15.101 7ff420f71700 0 log_channel(cluster) log [WRN] : replayed op client.18359173:904,900 used ino 0x100000051be but session next is 0x10000004bde
2019-02-18 21:26:15.101 7ff420f71700 0 log_channel(cluster) log [WRN] : replayed op client.18359173:905,900 used ino 0x100000051bf but session next is 0x10000004bde
2019-02-18 21:26:15.101 7ff420f71700 0 log_channel(cluster) log [WRN] : replayed op client.18359173:906,900 used ino 0x100000051c0 but session next is 0x10000004bde
2019-02-18 21:26:15.173 7ff420f71700 1 mds.0.307 replay_done
2019-02-18 21:26:15.173 7ff420f71700 1 mds.0.307 making mds journal writeable
2019-02-18 21:26:15.949 7ff429169700 1 mds.sg1vosrv12 Updating MDS map to version 308 from mon.1
2019-02-18 21:26:15.949 7ff429169700 1 mds.0.307 handle_mds_map i am now mds.0.307
2019-02-18 21:26:15.949 7ff429169700 1 mds.0.307 handle_mds_map state change up:replay --> up:reconnect
2019-02-18 21:26:15.949 7ff429169700 1 mds.0.307 reconnect_start
2019-02-18 21:26:15.949 7ff429169700 1 mds.0.307 reopen_log
2019-02-18 21:26:15.949 7ff429169700 1 mds.0.server reconnect_clients -- 10 sessions
2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.15227693 10.10.181.16:0/742284117 after 0.000405
2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.15258971 10.10.181.15:0/72759821 after 0.000475
2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.18164119 10.10.181.17:0/875193457 after 0.000545
2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.17592384 10.10.181.17:0/3643175079 after 0.000841
2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.18110760 10.10.181.16:0/3015216276 after 0.001458
2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.18355462 10.10.32.124:0/3176739197 after 0.001534
2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.17492882 10.10.181.18:0/1459513868 after 0.001623
2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.16348230 10.10.181.15:0/536186448 after 0.001670
2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.18337740 10.10.181.16:0/2022917557 after 0.001888
2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.16348125 10.10.181.16:0/4010683472 after 0.002474
2019-02-18 21:26:15.949 7ff429169700 1 mds.0.307 reconnect_done
2019-02-18 21:26:16.961 7ff429169700 1 mds.sg1vosrv12 Updating MDS map to version 309 from mon.1
2019-02-18 21:26:16.961 7ff429169700 1 mds.0.307 handle_mds_map i am now mds.0.307
2019-02-18 21:26:16.961 7ff429169700 1 mds.0.307 handle_mds_map state change up:reconnect --> up:rejoin
2019-02-18 21:26:16.961 7ff429169700 1 mds.0.307 rejoin_start
2019-02-18 21:26:16.965 7ff429169700 1 mds.0.307 rejoin_joint_start
2019-02-18 21:26:16.997 7ff422774700 1 mds.0.307 rejoin_done
2019-02-18 21:26:17.989 7ff429169700 1 mds.sg1vosrv12 Updating MDS map to version 310 from mon.1
2019-02-18 21:26:17.989 7ff429169700 1 mds.0.307 handle_mds_map i am now mds.0.307
2019-02-18 21:26:17.989 7ff429169700 1 mds.0.307 handle_mds_map state change up:rejoin --> up:active
2019-02-18 21:26:17.989 7ff429169700 1 mds.0.307 recovery_done -- successful recovery!
2019-02-18 21:26:17.989 7ff429169700 1 mds.0.307 active_start
2019-02-18 21:26:17.993 7ff429169700 1 mds.0.307 cluster recovered.
/home/jerome.poulin/GIT/ceph/src/mds/MDCache.cc: In function 'virtual void C_IO_MDC_TruncateFinish::finish(int)' thread 7ff422774700 time 2019-02-18 21:26:17.997688
/home/jerome.poulin/GIT/ceph/src/mds/MDCache.cc: 6476: FAILED assert(r == 0 || r == -2)
ceph version 13.2.4 (b10be4d44915a4d78a8e06aa31919e74927b142e) mimic (stable)
1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x102) [0x7ff431379642]
2: (()+0x26d807) [0x7ff431379807]
3: (C_MDC_FragmentFrozen::finish(int)+0) [0x55b38e305700]
4: (MDSIOContextBase::complete(int)+0x119) [0x55b38e4254e9]
5: (Finisher::finisher_thread_entry()+0x12e) [0x7ff431377bde]
6: (()+0x76db) [0x7ff430c846db]
7: (clone()+0x3f) [0x7ff42fe6a88f]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
2019-02-18 21:26:17.993 7ff422774700 -1 /home/jerome.poulin/GIT/ceph/src/mds/MDCache.cc: In function 'virtual void C_IO_MDC_TruncateFinish::finish(int)' thread 7ff422774700 time 2019-02-18 21:26:17.997688
/home/jerome.poulin/GIT/ceph/src/mds/MDCache.cc: 6476: FAILED assert(r == 0 || r == -2)

ceph version 13.2.4 (b10be4d44915a4d78a8e06aa31919e74927b142e) mimic (stable)
1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x102) [0x7ff431379642]
2: (()+0x26d807) [0x7ff431379807]
3: (C_MDC_FragmentFrozen::finish(int)+0) [0x55b38e305700]
4: (MDSIOContextBase::complete(int)+0x119) [0x55b38e4254e9]
5: (Finisher::finisher_thread_entry()+0x12e) [0x7ff431377bde]
6: (()+0x76db) [0x7ff430c846db]
7: (clone()+0x3f) [0x7ff42fe6a88f]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- begin dump of recent events ---
-768> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command perfcounters_dump hook 0x55b390db42d0
-767> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command 1 hook 0x55b390db42d0
-766> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command perf dump hook 0x55b390db42d0
-765> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command perfcounters_schema hook 0x55b390db42d0
-764> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command perf histogram dump hook 0x55b390db42d0
-763> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command 2 hook 0x55b390db42d0
-762> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command perf schema hook 0x55b390db42d0
-761> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command perf histogram schema hook 0x55b390db42d0
-760> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command perf reset hook 0x55b390db42d0
-759> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command config show hook 0x55b390db42d0
-758> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command config help hook 0x55b390db42d0
-757> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command config set hook 0x55b390db42d0
-756> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command config unset hook 0x55b390db42d0
-755> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command config get hook 0x55b390db42d0
-754> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command config diff hook 0x55b390db42d0
-753> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command config diff get hook 0x55b390db42d0
-752> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command log flush hook 0x55b390db42d0
-751> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command log dump hook 0x55b390db42d0
-750> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command log reopen hook 0x55b390db42d0
-749> 2019-02-18 21:26:09.365 7ff439f23440 5 asok(0x55b390db6000) register_command dump_mempools hook 0x55b390e6e068
-748> 2019-02-18 21:26:09.369 7ff439f23440 10 monclient: get_monmap_and_config
-747> 2019-02-18 21:26:09.369 7ff439f23440 10 monclient: build_initial_monmap
-746> 2019-02-18 21:26:09.369 7ff42c16f700 2 Event(0x55b390db6980 nevent=5000 time_id=1).set_owner idx=0 owner=140686688450304
-745> 2019-02-18 21:26:09.369 7ff42b96e700 2 Event(0x55b390db6bc0 nevent=5000 time_id=1).set_owner idx=1 owner=140686680057600
-744> 2019-02-18 21:26:09.369 7ff42b16d700 2 Event(0x55b390db6e00 nevent=5000 time_id=1).set_owner idx=2 owner=140686671664896
-743> 2019-02-18 21:26:09.369 7ff439f23440 1 Processor -- start
-742> 2019-02-18 21:26:09.369 7ff439f23440 1 -- - start start
-741> 2019-02-18 21:26:09.369 7ff439f23440 10 monclient: init
-740> 2019-02-18 21:26:09.369 7ff439f23440 5 adding auth protocol: cephx
-739> 2019-02-18 21:26:09.369 7ff439f23440 10 monclient: auth_supported 2 method cephx
-738> 2019-02-18 21:26:09.369 7ff439f23440 2 auth: KeyRing::load: loaded key file /var/lib/ceph/mds/ti-sg1vosrv12/keyring
-737> 2019-02-18 21:26:09.369 7ff439f23440 10 monclient: _reopen_session rank -1
-736> 2019-02-18 21:26:09.369 7ff439f23440 10 monclient(hunting): picked mon.noname-b con 0x55b39106a700 addr 10.10.0.17:6789/0
-735> 2019-02-18 21:26:09.369 7ff439f23440 10 monclient(hunting): picked mon.noname-c con 0x55b39106ae00 addr 10.10.0.18:6789/0
-734> 2019-02-18 21:26:09.369 7ff439f23440 1 -- - --> 10.10.0.17:6789/0 -- auth(proto 0 35 bytes epoch 0) v1 -- 0x55b390fd8780 con 0
-733> 2019-02-18 21:26:09.369 7ff439f23440 1 -- - --> 10.10.0.18:6789/0 -- auth(proto 0 35 bytes epoch 0) v1 -- 0x55b390fd8a00 con 0
-732> 2019-02-18 21:26:09.369 7ff439f23440 10 monclient(hunting): _renew_subs
-731> 2019-02-18 21:26:09.369 7ff439f23440 10 monclient(hunting): authenticate will time out at 2019-02-18 21:31:09.375174
-730> 2019-02-18 21:26:09.373 7ff42b96e700 1 -- 10.10.32.124:0/3011779849 learned_addr learned my addr 10.10.32.124:0/3011779849
-729> 2019-02-18 21:26:09.373 7ff42b96e700 2 -- 10.10.32.124:0/3011779849 >> 10.10.0.17:6789/0 conn(0x55b39106a700 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=0)._process_connection got newly_acked_seq 0 vs out_seq 0
-728> 2019-02-18 21:26:09.373 7ff42b16d700 2 -- 10.10.32.124:0/3011779849 >> 10.10.0.18:6789/0 conn(0x55b39106ae00 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=0)._process_connection got newly_acked_seq 0 vs out_seq 0
-727> 2019-02-18 21:26:09.373 7ff42b96e700 5 -- 10.10.32.124:0/3011779849 >> 10.10.0.17:6789/0 conn(0x55b39106a700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110893 cs=1 l=1). rx mon.1 seq 1 0x55b390db7b00 mon_map magic: 0 v1
-726> 2019-02-18 21:26:09.373 7ff42b96e700 5 -- 10.10.32.124:0/3011779849 >> 10.10.0.17:6789/0 conn(0x55b39106a700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110893 cs=1 l=1). rx mon.1 seq 2 0x55b390fd8780 auth_reply(proto 2 0 (0) Success) v1
-725> 2019-02-18 21:26:09.373 7ff42a96c700 1 -- 10.10.32.124:0/3011779849 <== mon.1 10.10.0.17:6789/0 1 ==== mon_map magic: 0 v1 ==== 367+0+0 (3561475368 0 0) 0x55b390db7b00 con 0x55b39106a700
-724> 2019-02-18 21:26:09.373 7ff42a96c700 10 monclient(hunting): handle_monmap mon_map magic: 0 v1
-723> 2019-02-18 21:26:09.373 7ff42a96c700 10 monclient(hunting): got monmap 8, mon.noname-b is now rank -1
-722> 2019-02-18 21:26:09.373 7ff42a96c700 10 monclient(hunting): dump:
epoch 8
fsid e98e202d-9b26-4f1c-a40c-3d4a1bff56a4
last_changed 2018-10-04 20:15:04.556706
created 2017-11-29 13:32:12.934114
0: 10.10.0.16:6789/0 mon.8
1: 10.10.0.17:6789/0 mon.12
2: 10.10.0.18:6789/0 mon.25

-721> 2019-02-18 21:26:09.373 7ff42a96c700 1 -- 10.10.32.124:0/3011779849 <== mon.1 10.10.0.17:6789/0 2 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 33+0+0 (2127468795 0 0) 0x55b390fd8780 con 0x55b39106a700
-720> 2019-02-18 21:26:09.373 7ff42a96c700 10 monclient(hunting): my global_id is 18579223
-719> 2019-02-18 21:26:09.373 7ff42a96c700 1 -- 10.10.32.124:0/3011779849 --> 10.10.0.17:6789/0 -- auth(proto 2 32 bytes epoch 0) v1 -- 0x55b390fd8f00 con 0
-718> 2019-02-18 21:26:09.373 7ff42b16d700 5 -- 10.10.32.124:0/3011779849 >> 10.10.0.18:6789/0 conn(0x55b39106ae00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110858 cs=1 l=1). rx mon.2 seq 1 0x55b390db7d40 mon_map magic: 0 v1
-717> 2019-02-18 21:26:09.373 7ff42b16d700 5 -- 10.10.32.124:0/3011779849 >> 10.10.0.18:6789/0 conn(0x55b39106ae00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110858 cs=1 l=1). rx mon.2 seq 2 0x55b390fd8a00 auth_reply(proto 2 0 (0) Success) v1
-716> 2019-02-18 21:26:09.373 7ff42a96c700 1 -- 10.10.32.124:0/3011779849 <== mon.2 10.10.0.18:6789/0 1 ==== mon_map magic: 0 v1 ==== 367+0+0 (3561475368 0 0) 0x55b390db7d40 con 0x55b39106ae00
-715> 2019-02-18 21:26:09.373 7ff42a96c700 10 monclient(hunting): handle_monmap mon_map magic: 0 v1
-714> 2019-02-18 21:26:09.373 7ff42a96c700 10 monclient(hunting): got monmap 8, mon.25 is now rank 2
-713> 2019-02-18 21:26:09.373 7ff42a96c700 10 monclient(hunting): dump:
epoch 8
fsid e98e202d-9b26-4f1c-a40c-3d4a1bff56a4
last_changed 2018-10-04 20:15:04.556706
created 2017-11-29 13:32:12.934114
0: 10.10.0.16:6789/0 mon.8
1: 10.10.0.17:6789/0 mon.12
2: 10.10.0.18:6789/0 mon.25

-712> 2019-02-18 21:26:09.373 7ff42a96c700 1 -- 10.10.32.124:0/3011779849 <== mon.2 10.10.0.18:6789/0 2 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 33+0+0 (4131541160 0 0) 0x55b390fd8a00 con 0x55b39106ae00
-711> 2019-02-18 21:26:09.373 7ff42a96c700 10 monclient(hunting): my global_id is 18569267
-710> 2019-02-18 21:26:09.373 7ff42a96c700 1 -- 10.10.32.124:0/3011779849 --> 10.10.0.18:6789/0 -- auth(proto 2 32 bytes epoch 0) v1 -- 0x55b390fd8780 con 0
-709> 2019-02-18 21:26:09.373 7ff42b96e700 5 -- 10.10.32.124:0/3011779849 >> 10.10.0.17:6789/0 conn(0x55b39106a700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110893 cs=1 l=1). rx mon.1 seq 3 0x55b390fd8f00 auth_reply(proto 2 0 (0) Success) v1
-708> 2019-02-18 21:26:09.373 7ff42a96c700 1 -- 10.10.32.124:0/3011779849 <== mon.1 10.10.0.17:6789/0 3 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 222+0+0 (2259784909 0 0) 0x55b390fd8f00 con 0x55b39106a700
-707> 2019-02-18 21:26:09.373 7ff42a96c700 1 -- 10.10.32.124:0/3011779849 >> 10.10.0.18:6789/0 conn(0x55b39106ae00 :-1 s=STATE_OPEN pgs=2110858 cs=1 l=1).mark_down
-706> 2019-02-18 21:26:09.373 7ff42a96c700 2 -- 10.10.32.124:0/3011779849 >> 10.10.0.18:6789/0 conn(0x55b39106ae00 :-1 s=STATE_OPEN pgs=2110858 cs=1 l=1)._stop
-705> 2019-02-18 21:26:09.373 7ff42a96c700 1 monclient: found mon.12
-704> 2019-02-18 21:26:09.373 7ff42a96c700 10 monclient: _send_mon_message to mon.12 at 10.10.0.17:6789/0
-703> 2019-02-18 21:26:09.373 7ff42a96c700 1 -- 10.10.32.124:0/3011779849 --> 10.10.0.17:6789/0 -- mon_subscribe({config=0+,monmap=0+}) v3 -- 0x55b390db6fc0 con 0
-702> 2019-02-18 21:26:09.373 7ff42a96c700 10 monclient: _check_auth_rotating renewing rotating keys (they expired before 2019-02-18 21:25:39.377341)
-701> 2019-02-18 21:26:09.373 7ff42a96c700 10 monclient: _send_mon_message to mon.12 at 10.10.0.17:6789/0
-700> 2019-02-18 21:26:09.373 7ff42a96c700 1 -- 10.10.32.124:0/3011779849 --> 10.10.0.17:6789/0 -- auth(proto 2 2 bytes epoch 0) v1 -- 0x55b390fd8a00 con 0
-699> 2019-02-18 21:26:09.373 7ff439f23440 5 monclient: authenticate success, global_id 18579223
-698> 2019-02-18 21:26:09.373 7ff42b96e700 5 -- 10.10.32.124:0/3011779849 >> 10.10.0.17:6789/0 conn(0x55b39106a700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110893 cs=1 l=1). rx mon.1 seq 4 0x55b390db6fc0 config(0 keys) v1
-697> 2019-02-18 21:26:09.373 7ff42b96e700 5 -- 10.10.32.124:0/3011779849 >> 10.10.0.17:6789/0 conn(0x55b39106a700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110893 cs=1 l=1). rx mon.1 seq 5 0x55b390db7b00 mon_map magic: 0 v1
-696> 2019-02-18 21:26:09.373 7ff42a96c700 1 -- 10.10.32.124:0/3011779849 <== mon.1 10.10.0.17:6789/0 4 ==== config(0 keys) v1 ==== 4+0+0 (0 0 0) 0x55b390db6fc0 con 0x55b39106a700
-695> 2019-02-18 21:26:09.373 7ff42a96c700 10 monclient: handle_config config(0 keys) v1
-694> 2019-02-18 21:26:09.373 7ff42b96e700 5 -- 10.10.32.124:0/3011779849 >> 10.10.0.17:6789/0 conn(0x55b39106a700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110893 cs=1 l=1). rx mon.1 seq 6 0x55b390fd8a00 auth_reply(proto 2 0 (0) Success) v1
-693> 2019-02-18 21:26:09.373 7ff42a96c700 1 -- 10.10.32.124:0/3011779849 <== mon.1 10.10.0.17:6789/0 5 ==== mon_map magic: 0 v1 ==== 367+0+0 (3561475368 0 0) 0x55b390db7b00 con 0x55b39106a700
-692> 2019-02-18 21:26:09.373 7ff42a96c700 10 monclient: handle_monmap mon_map magic: 0 v1
-691> 2019-02-18 21:26:09.373 7ff42a96c700 10 monclient: got monmap 8, mon.12 is now rank 1
-690> 2019-02-18 21:26:09.373 7ff42a96c700 10 monclient: dump:
epoch 8
fsid e98e202d-9b26-4f1c-a40c-3d4a1bff56a4
last_changed 2018-10-04 20:15:04.556706
created 2017-11-29 13:32:12.934114
0: 10.10.0.16:6789/0 mon.8
1: 10.10.0.17:6789/0 mon.12
2: 10.10.0.18:6789/0 mon.25

-689> 2019-02-18 21:26:09.373 7ff429169700 4 set_mon_vals no callback set
-688> 2019-02-18 21:26:09.373 7ff439f23440 10 monclient: get_monmap_and_config success
-687> 2019-02-18 21:26:09.373 7ff439f23440 10 monclient: shutdown
-686> 2019-02-18 21:26:09.373 7ff42a96c700 1 -- 10.10.32.124:0/3011779849 <== mon.1 10.10.0.17:6789/0 6 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 194+0+0 (2189693056 0 0) 0x55b390fd8a00 con 0x55b39106a700
-685> 2019-02-18 21:26:09.373 7ff439f23440 1 -- 10.10.32.124:0/3011779849 >> 10.10.0.17:6789/0 conn(0x55b39106a700 :-1 s=STATE_OPEN pgs=2110893 cs=1 l=1).mark_down
-684> 2019-02-18 21:26:09.373 7ff439f23440 2 -- 10.10.32.124:0/3011779849 >> 10.10.0.17:6789/0 conn(0x55b39106a700 :-1 s=STATE_OPEN pgs=2110893 cs=1 l=1)._stop
-683> 2019-02-18 21:26:09.373 7ff42a96c700 10 monclient: discarding stray monitor message auth_reply(proto 2 0 (0) Success) v1
-682> 2019-02-18 21:26:09.377 7ff439f23440 1 -- 10.10.32.124:0/3011779849 shutdown_connections
-681> 2019-02-18 21:26:09.377 7ff439f23440 5 -- 10.10.32.124:0/3011779849 shutdown_connections mark down 10.10.0.18:6789/0 0x55b39106ae00
-680> 2019-02-18 21:26:09.377 7ff439f23440 5 -- 10.10.32.124:0/3011779849 shutdown_connections mark down 10.10.0.17:6789/0 0x55b39106a700
-679> 2019-02-18 21:26:09.377 7ff439f23440 5 -- 10.10.32.124:0/3011779849 shutdown_connections delete 0x55b39106a700
-678> 2019-02-18 21:26:09.377 7ff439f23440 5 -- 10.10.32.124:0/3011779849 shutdown_connections delete 0x55b39106ae00
-677> 2019-02-18 21:26:09.377 7ff439f23440 1 -- 10.10.32.124:0/3011779849 shutdown_connections
-676> 2019-02-18 21:26:09.377 7ff439f23440 1 -- 10.10.32.124:0/3011779849 wait complete.
-675> 2019-02-18 21:26:09.377 7ff439f23440 1 -- 10.10.32.124:0/3011779849 >> 10.10.32.124:0/3011779849 conn(0x55b39106a000 :-1 s=STATE_NONE pgs=0 cs=0 l=0).mark_down
-674> 2019-02-18 21:26:09.377 7ff439f23440 2 -- 10.10.32.124:0/3011779849 >> 10.10.32.124:0/3011779849 conn(0x55b39106a000 :-1 s=STATE_NONE pgs=0 cs=0 l=0)._stop
-673> 2019-02-18 21:26:09.377 7ff439f23440 0 set uid:gid to 64045:64045 (ceph:ceph)
-672> 2019-02-18 21:26:09.377 7ff439f23440 0 ceph version 13.2.4 (b10be4d44915a4d78a8e06aa31919e74927b142e) mimic (stable), process ceph-mds, pid 32244
-671> 2019-02-18 21:26:09.377 7ff439f23440 0 pidfile_write: ignore empty --pid-file
-670> 2019-02-18 21:26:09.377 7ff439f23440 5 asok(0x55b390db6000) init /var/run/ceph/ti-mds.sg1vosrv12.asok
-669> 2019-02-18 21:26:09.377 7ff439f23440 5 asok(0x55b390db6000) bind_and_listen /var/run/ceph/ti-mds.sg1vosrv12.asok
-668> 2019-02-18 21:26:09.377 7ff439f23440 5 asok(0x55b390db6000) register_command 0 hook 0x55b390db3380
-667> 2019-02-18 21:26:09.377 7ff439f23440 5 asok(0x55b390db6000) register_command version hook 0x55b390db3380
-666> 2019-02-18 21:26:09.377 7ff439f23440 5 asok(0x55b390db6000) register_command git_version hook 0x55b390db3380
-665> 2019-02-18 21:26:09.377 7ff439f23440 5 asok(0x55b390db6000) register_command help hook 0x55b390db4430
-664> 2019-02-18 21:26:09.377 7ff439f23440 5 asok(0x55b390db6000) register_command get_command_descriptions hook 0x55b390db41c0
-663> 2019-02-18 21:26:09.377 7ff42a16b700 5 asok(0x55b390db6000) entry start
-662> 2019-02-18 21:26:09.377 7ff439f23440 1 -- 0.0.0.0:6800/3814621597 _finish_bind bind my_inst.addr is 0.0.0.0:6800/3814621597
-661> 2019-02-18 21:26:09.377 7ff439f23440 10 monclient: build_initial_monmap
-660> 2019-02-18 21:26:09.377 7ff439f23440 1 -- 0.0.0.0:6800/3814621597 start start
-659> 2019-02-18 21:26:09.377 7ff439f23440 5 adding auth protocol: cephx
-658> 2019-02-18 21:26:09.377 7ff439f23440 5 adding auth protocol: cephx
-657> 2019-02-18 21:26:09.377 7ff439f23440 1 Processor -- start
-656> 2019-02-18 21:26:09.381 7ff439f23440 10 monclient: init
-655> 2019-02-18 21:26:09.381 7ff439f23440 5 adding auth protocol: cephx
-654> 2019-02-18 21:26:09.381 7ff439f23440 10 monclient: auth_supported 2 method cephx
-653> 2019-02-18 21:26:09.381 7ff439f23440 2 auth: KeyRing::load: loaded key file /var/lib/ceph/mds/ti-sg1vosrv12/keyring
-652> 2019-02-18 21:26:09.381 7ff439f23440 10 monclient: _reopen_session rank -1
-651> 2019-02-18 21:26:09.381 7ff439f23440 10 monclient(hunting): picked mon.noname-a con 0x55b39106a700 addr 10.10.0.16:6789/0
-650> 2019-02-18 21:26:09.381 7ff439f23440 10 monclient(hunting): picked mon.noname-b con 0x55b39106b500 addr 10.10.0.17:6789/0
-649> 2019-02-18 21:26:09.381 7ff439f23440 1 -- 0.0.0.0:6800/3814621597 --> 10.10.0.16:6789/0 -- auth(proto 0 35 bytes epoch 0) v1 -- 0x55b390fd8c80 con 0
-648> 2019-02-18 21:26:09.381 7ff439f23440 1 -- 0.0.0.0:6800/3814621597 --> 10.10.0.17:6789/0 -- auth(proto 0 35 bytes epoch 0) v1 -- 0x55b390fd8f00 con 0
-647> 2019-02-18 21:26:09.381 7ff439f23440 10 monclient(hunting): _renew_subs
-646> 2019-02-18 21:26:09.381 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 learned_addr learned my addr 10.10.32.124:6800/3814621597
-645> 2019-02-18 21:26:09.381 7ff42b16d700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-644> 2019-02-18 21:26:09.381 7ff42b96e700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6789/0 conn(0x55b39106a700 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-643> 2019-02-18 21:26:09.381 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 1 0x55b390db7b00 mon_map magic: 0 v1
-642> 2019-02-18 21:26:09.381 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 2 0x55b390fd8780 auth_reply(proto 2 0 (0) Success) v1
-641> 2019-02-18 21:26:09.381 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 1 ==== mon_map magic: 0 v1 ==== 367+0+0 (3561475368 0 0) 0x55b390db7b00 con 0x55b39106b500
-640> 2019-02-18 21:26:09.381 7ff429169700 10 monclient(hunting): handle_monmap mon_map magic: 0 v1
-639> 2019-02-18 21:26:09.381 7ff429169700 10 monclient(hunting): got monmap 8, mon.noname-b is now rank -1
-638> 2019-02-18 21:26:09.381 7ff429169700 10 monclient(hunting): dump:
epoch 8
fsid e98e202d-9b26-4f1c-a40c-3d4a1bff56a4
last_changed 2018-10-04 20:15:04.556706
created 2017-11-29 13:32:12.934114
0: 10.10.0.16:6789/0 mon.8
1: 10.10.0.17:6789/0 mon.12
2: 10.10.0.18:6789/0 mon.25

-637> 2019-02-18 21:26:09.381 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 2 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 33+0+0 (3605926566 0 0) 0x55b390fd8780 con 0x55b39106b500
-636> 2019-02-18 21:26:09.381 7ff429169700 10 monclient(hunting): my global_id is 18579226
-635> 2019-02-18 21:26:09.381 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6789/0 -- auth(proto 2 32 bytes epoch 0) v1 -- 0x55b390fd9680 con 0
-634> 2019-02-18 21:26:09.381 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6789/0 conn(0x55b39106a700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=1867 cs=1 l=1). rx mon.0 seq 1 0x55b390db7d40 mon_map magic: 0 v1
-633> 2019-02-18 21:26:09.381 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mon.0 10.10.0.16:6789/0 1 ==== mon_map magic: 0 v1 ==== 367+0+0 (3561475368 0 0) 0x55b390db7d40 con 0x55b39106a700
-632> 2019-02-18 21:26:09.381 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6789/0 conn(0x55b39106a700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=1867 cs=1 l=1). rx mon.0 seq 2 0x55b390fd8c80 auth_reply(proto 2 0 (0) Success) v1
-631> 2019-02-18 21:26:09.381 7ff429169700 10 monclient(hunting): handle_monmap mon_map magic: 0 v1
-630> 2019-02-18 21:26:09.381 7ff429169700 10 monclient(hunting): got monmap 8, mon.8 is now rank 0
-629> 2019-02-18 21:26:09.381 7ff429169700 10 monclient(hunting): dump:
epoch 8
fsid e98e202d-9b26-4f1c-a40c-3d4a1bff56a4
last_changed 2018-10-04 20:15:04.556706
created 2017-11-29 13:32:12.934114
0: 10.10.0.16:6789/0 mon.8
1: 10.10.0.17:6789/0 mon.12
2: 10.10.0.18:6789/0 mon.25

-628> 2019-02-18 21:26:09.381 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mon.0 10.10.0.16:6789/0 2 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 33+0+0 (956441187 0 0) 0x55b390fd8c80 con 0x55b39106a700
-627> 2019-02-18 21:26:09.381 7ff429169700 10 monclient(hunting): my global_id is 18559194
-626> 2019-02-18 21:26:09.381 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6789/0 -- auth(proto 2 32 bytes epoch 0) v1 -- 0x55b390fd8780 con 0
-625> 2019-02-18 21:26:09.381 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 3 0x55b390fd9680 auth_reply(proto 2 0 (0) Success) v1
-624> 2019-02-18 21:26:09.381 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 3 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 222+0+0 (575399298 0 0) 0x55b390fd9680 con 0x55b39106b500
-623> 2019-02-18 21:26:09.381 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6789/0 -- auth(proto 2 181 bytes epoch 0) v1 -- 0x55b390fd8c80 con 0
-622> 2019-02-18 21:26:09.381 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6789/0 conn(0x55b39106a700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=1867 cs=1 l=1). rx mon.0 seq 3 0x55b390fd8780 auth_reply(proto 2 0 (0) Success) v1
-621> 2019-02-18 21:26:09.381 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mon.0 10.10.0.16:6789/0 3 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 222+0+0 (328768752 0 0) 0x55b390fd8780 con 0x55b39106a700
-620> 2019-02-18 21:26:09.381 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6789/0 -- auth(proto 2 181 bytes epoch 0) v1 -- 0x55b390fd9680 con 0
-619> 2019-02-18 21:26:09.381 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 4 0x55b390fd8c80 auth_reply(proto 2 0 (0) Success) v1
-618> 2019-02-18 21:26:09.381 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 4 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 847+0+0 (2920215892 0 0) 0x55b390fd8c80 con 0x55b39106b500
-617> 2019-02-18 21:26:09.381 7ff429169700 1 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6789/0 conn(0x55b39106a700 :-1 s=STATE_OPEN pgs=1867 cs=1 l=1).mark_down
-616> 2019-02-18 21:26:09.381 7ff429169700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6789/0 conn(0x55b39106a700 :-1 s=STATE_OPEN pgs=1867 cs=1 l=1)._stop
-615> 2019-02-18 21:26:09.381 7ff429169700 1 monclient: found mon.12
-614> 2019-02-18 21:26:09.381 7ff429169700 10 monclient: _send_mon_message to mon.12 at 10.10.0.17:6789/0
-613> 2019-02-18 21:26:09.381 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6789/0 -- mon_subscribe({config=0+,monmap=0+}) v3 -- 0x55b390db7440 con 0
-612> 2019-02-18 21:26:09.381 7ff429169700 10 monclient: _check_auth_rotating renewing rotating keys (they expired before 2019-02-18 21:25:39.385660)
-611> 2019-02-18 21:26:09.381 7ff429169700 10 monclient: _send_mon_message to mon.12 at 10.10.0.17:6789/0
-610> 2019-02-18 21:26:09.381 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6789/0 -- auth(proto 2 2 bytes epoch 0) v1 -- 0x55b390fd8780 con 0
-609> 2019-02-18 21:26:09.381 7ff439f23440 5 monclient: authenticate success, global_id 18579226
-608> 2019-02-18 21:26:09.381 7ff439f23440 10 monclient: wait_auth_rotating waiting (until 2019-02-18 21:26:39.385684)
-607> 2019-02-18 21:26:09.381 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 5 0x55b390db7440 config(0 keys) v1
-606> 2019-02-18 21:26:09.381 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 6 0x55b390db6fc0 mon_map magic: 0 v1
-605> 2019-02-18 21:26:09.381 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 5 ==== config(0 keys) v1 ==== 4+0+0 (0 0 0) 0x55b390db7440 con 0x55b39106b500
-604> 2019-02-18 21:26:09.381 7ff429169700 10 monclient: handle_config config(0 keys) v1
-603> 2019-02-18 21:26:09.381 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 7 0x55b390fd8780 auth_reply(proto 2 0 (0) Success) v1
-602> 2019-02-18 21:26:09.381 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 6 ==== mon_map magic: 0 v1 ==== 367+0+0 (3561475368 0 0) 0x55b390db6fc0 con 0x55b39106b500
-601> 2019-02-18 21:26:09.381 7ff429169700 10 monclient: handle_monmap mon_map magic: 0 v1
-600> 2019-02-18 21:26:09.381 7ff429169700 10 monclient: got monmap 8, mon.12 is now rank 1
-599> 2019-02-18 21:26:09.381 7ff426f7d700 4 set_mon_vals no callback set
-598> 2019-02-18 21:26:09.381 7ff429169700 10 monclient: dump:
epoch 8
fsid e98e202d-9b26-4f1c-a40c-3d4a1bff56a4
last_changed 2018-10-04 20:15:04.556706
created 2017-11-29 13:32:12.934114
0: 10.10.0.16:6789/0 mon.8
1: 10.10.0.17:6789/0 mon.12
2: 10.10.0.18:6789/0 mon.25

-597> 2019-02-18 21:26:09.381 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 7 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 194+0+0 (106690329 0 0) 0x55b390fd8780 con 0x55b39106b500
-596> 2019-02-18 21:26:09.381 7ff429169700 10 monclient: _check_auth_rotating have uptodate secrets (they expire after 2019-02-18 21:25:39.386050)
-595> 2019-02-18 21:26:09.381 7ff439f23440 10 monclient: wait_auth_rotating done
-594> 2019-02-18 21:26:09.381 7ff439f23440 10 monclient: _renew_subs
-593> 2019-02-18 21:26:09.381 7ff439f23440 10 monclient: _send_mon_message to mon.12 at 10.10.0.17:6789/0
-592> 2019-02-18 21:26:09.381 7ff439f23440 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6789/0 -- mon_subscribe({mdsmap=0+,mgrmap=0+}) v3 -- 0x55b390db7680 con 0
-591> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command status hook 0x55b390db4490
-590> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command dump_ops_in_flight hook 0x55b390db4490
-589> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command ops hook 0x55b390db4490
-588> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command dump_blocked_ops hook 0x55b390db4490
-587> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command dump_historic_ops hook 0x55b390db4490
-586> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command dump_historic_ops_by_duration hook 0x55b390db4490
-585> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command scrub_path hook 0x55b390db4490
-584> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command tag path hook 0x55b390db4490
-583> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command flush_path hook 0x55b390db4490
-582> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command export dir hook 0x55b390db4490
-581> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command dump cache hook 0x55b390db4490
-580> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command cache status hook 0x55b390db4490
-579> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command cache drop hook 0x55b390db4490
-578> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command dump tree hook 0x55b390db4490
-577> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command dump loads hook 0x55b390db4490
-576> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command dump snaps hook 0x55b390db4490
-575> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command session evict hook 0x55b390db4490
-574> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command osdmap barrier hook 0x55b390db4490
-573> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command session ls hook 0x55b390db4490
-572> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command flush journal hook 0x55b390db4490
-571> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command force_readonly hook 0x55b390db4490
-570> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command get subtrees hook 0x55b390db4490
-569> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command dirfrag split hook 0x55b390db4490
-568> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command dirfrag merge hook 0x55b390db4490
-567> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command dirfrag ls hook 0x55b390db4490
-566> 2019-02-18 21:26:09.381 7ff439f23440 5 asok(0x55b390db6000) register_command openfiles ls hook 0x55b390db4490
-565> 2019-02-18 21:26:09.381 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 8 0x55b390fd8f00 mdsmap(e 305) v1
-564> 2019-02-18 21:26:09.381 7ff42577a700 5 mds.beacon.sg1vosrv12 Sending beacon up:boot seq 1
-563> 2019-02-18 21:26:09.381 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 8 ==== mdsmap(e 305) v1 ==== 493+0+0 (1327100912 0 0) 0x55b390fd8f00 con 0x55b39106b500
-562> 2019-02-18 21:26:09.381 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 9 0x55b390e1e600 mgrmap(e 225) v1
-561> 2019-02-18 21:26:09.405 7ff42577a700 10 monclient: _send_mon_message to mon.12 at 10.10.0.17:6789/0
-560> 2019-02-18 21:26:09.405 7ff42577a700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6789/0 -- mdsbeacon(18579226/sg1vosrv12 up:boot seq 1 v0) v7 -- 0x55b390fc8a80 con 0
-559> 2019-02-18 21:26:09.405 7ff429169700 1 mds.sg1vosrv12 Updating MDS map to version 305 from mon.1
-558> 2019-02-18 21:26:09.405 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 9 ==== mgrmap(e 225) v1 ==== 1678+0+0 (2759681480 0 0) 0x55b390e1e600 con 0x55b39106b500
-557> 2019-02-18 21:26:09.405 7ff429169700 4 mgrc handle_mgr_map Got map version 225
-556> 2019-02-18 21:26:09.405 7ff429169700 4 mgrc handle_mgr_map Active mgr is now 10.10.0.16:6800/1906091
-555> 2019-02-18 21:26:09.405 7ff429169700 4 mgrc reconnect Starting new session with 10.10.0.16:6800/1906091
-554> 2019-02-18 21:26:09.405 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6800/1906091 -- mgropen(unknown.sg1vosrv12) v3 -- 0x55b39108a000 con 0
-553> 2019-02-18 21:26:09.405 7ff42b96e700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6800/1906091 conn(0x55b39106d100 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-552> 2019-02-18 21:26:09.405 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6800/1906091 conn(0x55b39106d100 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=1579 cs=1 l=1). rx mgr.18564296 seq 1 0x55b390e041e0 mgrconfigure(period=5, threshold=5) v2
-551> 2019-02-18 21:26:09.409 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mgr.18564296 10.10.0.16:6800/1906091 1 ==== mgrconfigure(period=5, threshold=5) v2 ==== 8+0+0 (3460719617 0 0) 0x55b390e041e0 con 0x55b39106d100
-550> 2019-02-18 21:26:09.409 7ff429169700 4 mgrc handle_mgr_configure stats_period=5
-549> 2019-02-18 21:26:09.409 7ff429169700 4 mgrc handle_mgr_configure updated stats threshold: 5
-548> 2019-02-18 21:26:09.409 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6800/1906091 -- mgrreport(unknown.sg1vosrv12 +0-0 packed 6) v6 -- 0x55b390fc8e00 con 0
-547> 2019-02-18 21:26:13.405 7ff42577a700 5 mds.beacon.sg1vosrv12 Sending beacon up:boot seq 2
-546> 2019-02-18 21:26:13.425 7ff42577a700 10 monclient: _send_mon_message to mon.12 at 10.10.0.17:6789/0
-545> 2019-02-18 21:26:13.425 7ff42577a700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6789/0 -- mdsbeacon(18579226/sg1vosrv12 up:boot seq 2 v305) v7 -- 0x55b390fc9180 con 0
-544> 2019-02-18 21:26:13.525 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 10 0x55b390fd8c80 mdsmap(e 306) v1
-543> 2019-02-18 21:26:13.525 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 10 ==== mdsmap(e 306) v1 ==== 617+0+0 (610308565 0 0) 0x55b390fd8c80 con 0x55b39106b500
-542> 2019-02-18 21:26:13.525 7ff429169700 1 mds.sg1vosrv12 Updating MDS map to version 306 from mon.1
-541> 2019-02-18 21:26:13.525 7ff429169700 5 mds.beacon.sg1vosrv12 set_want_state: up:boot -> up:standby
-540> 2019-02-18 21:26:13.525 7ff429169700 1 mds.sg1vosrv12 Map has assigned me to become a standby
-539> 2019-02-18 21:26:13.525 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 11 0x55b390fc8a80 mdsbeacon(18579226/sg1vosrv12 up:boot seq 2 v306) v7
-538> 2019-02-18 21:26:13.525 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 11 ==== mdsbeacon(18579226/sg1vosrv12 up:boot seq 2 v306) v7 ==== 139+0+0 (2442505371 0 0) 0x55b390fc8a80 con 0x55b39106b500
-537> 2019-02-18 21:26:13.525 7ff42b16d700 5 mds.beacon.sg1vosrv12 received beacon reply up:boot seq 2 rtt 0.120001
-536> 2019-02-18 21:26:13.557 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 12 0x55b390fd8780 mdsmap(e 307) v1
-535> 2019-02-18 21:26:13.557 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 12 ==== mdsmap(e 307) v1 ==== 657+0+0 (721141015 0 0) 0x55b390fd8780 con 0x55b39106b500
-534> 2019-02-18 21:26:13.557 7ff429169700 1 mds.sg1vosrv12 Updating MDS map to version 307 from mon.1
-533> 2019-02-18 21:26:13.557 7ff429169700 4 mds.0.purge_queue operator(): data pool 5 not found in OSDMap
-532> 2019-02-18 21:26:13.557 7ff429169700 4 mds.0.purge_queue operator(): data pool 114 not found in OSDMap
-531> 2019-02-18 21:26:13.557 7ff429169700 5 asok(0x55b390db6000) register_command objecter_requests hook 0x55b390db4650
-530> 2019-02-18 21:26:13.557 7ff429169700 10 monclient: _renew_subs
-529> 2019-02-18 21:26:13.557 7ff429169700 10 monclient: _send_mon_message to mon.12 at 10.10.0.17:6789/0
-528> 2019-02-18 21:26:13.557 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6789/0 -- mon_subscribe({osdmap=0}) v3 -- 0x55b390db8640 con 0
-527> 2019-02-18 21:26:13.557 7ff429169700 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)
-526> 2019-02-18 21:26:13.557 7ff429169700 4 mds.0.purge_queue operator(): data pool 5 not found in OSDMap
-525> 2019-02-18 21:26:13.557 7ff429169700 4 mds.0.purge_queue operator(): data pool 114 not found in OSDMap
-524> 2019-02-18 21:26:13.557 7ff429169700 4 mds.0.0 handle_osd_map epoch 0, 0 new blacklist entries
-523> 2019-02-18 21:26:13.557 7ff429169700 1 mds.0.307 handle_mds_map i am now mds.0.307
-522> 2019-02-18 21:26:13.557 7ff429169700 1 mds.0.307 handle_mds_map state change up:boot --> up:replay
-521> 2019-02-18 21:26:13.557 7ff429169700 5 mds.beacon.sg1vosrv12 set_want_state: up:standby -> up:replay
-520> 2019-02-18 21:26:13.557 7ff429169700 1 mds.0.307 replay_start
-519> 2019-02-18 21:26:13.557 7ff429169700 1 mds.0.307 recovery set is
-518> 2019-02-18 21:26:13.557 7ff429169700 1 mds.0.307 waiting for osdmap 87591 (which blacklists prior instance)
-517> 2019-02-18 21:26:13.557 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 13 0x55b390e6f080 osd_map(87591..87591 src has 87076..87591) v4
-516> 2019-02-18 21:26:13.557 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 13 ==== osd_map(87591..87591 src has 87076..87591) v4 ==== 18124+0+0 (740140877 0 0) 0x55b390e6f080 con 0x55b39106b500
-515> 2019-02-18 21:26:13.557 7ff429169700 4 mds.0.307 handle_osd_map epoch 87591, 0 new blacklist entries
-514> 2019-02-18 21:26:13.557 7ff429169700 10 monclient: _renew_subs
-513> 2019-02-18 21:26:13.557 7ff429169700 10 monclient: _send_mon_message to mon.12 at 10.10.0.17:6789/0
-512> 2019-02-18 21:26:13.557 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6789/0 -- mon_subscribe({osdmap=87592}) v3 -- 0x55b390db8880 con 0
-511> 2019-02-18 21:26:13.557 7ff422774700 2 mds.0.307 boot_start 0: opening inotable
-510> 2019-02-18 21:26:13.557 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6801/2707522 -- osd_op(unknown.0.307:1 4.13 4:c91d4a1d:::mds0_inotable:head [read 0~0] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108a340 con 0
-509> 2019-02-18 21:26:13.557 7ff422774700 2 mds.0.307 boot_start 0: opening sessionmap
-508> 2019-02-18 21:26:13.557 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6800/2707654 -- osd_op(unknown.0.307:2 4.b 4:d0630e4c:::mds0_sessionmap:head [omap-get-header,omap-get-vals] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108a680 con 0
-507> 2019-02-18 21:26:13.561 7ff422774700 2 mds.0.307 boot_start 0: opening mds log
-506> 2019-02-18 21:26:13.561 7ff422774700 5 mds.0.log open discovering log bounds
-505> 2019-02-18 21:26:13.561 7ff422774700 2 mds.0.307 boot_start 0: opening purge queue (async)
-504> 2019-02-18 21:26:13.561 7ff422774700 4 mds.0.purge_queue open: opening
-503> 2019-02-18 21:26:13.561 7ff421f73700 4 mds.0.journalpointer Reading journal pointer '400.00000000'
-502> 2019-02-18 21:26:13.561 7ff422774700 1 mds.0.journaler.pq(ro) recover start
-501> 2019-02-18 21:26:13.561 7ff422774700 1 mds.0.journaler.pq(ro) read_head
-500> 2019-02-18 21:26:13.561 7ff421f73700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6804/2707580 -- osd_op(unknown.0.307:3 4.f 4:f1f69726:::400.00000000:head [read 0~0] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108ad00 con 0
-499> 2019-02-18 21:26:13.561 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6814/1907788 -- osd_op(unknown.0.307:4 4.15 4:aa448500:::500.00000000:head [read 0~0] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108a9c0 con 0
-498> 2019-02-18 21:26:13.561 7ff422774700 2 mds.0.307 boot_start 0: loading open file table (async)
-497> 2019-02-18 21:26:13.561 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6820/2707789 -- osd_op(unknown.0.307:5 4.6 4:654134d2:::mds0_openfiles.0:head [omap-get-header,omap-get-vals] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108b040 con 0
-496> 2019-02-18 21:26:13.561 7ff422774700 2 mds.0.307 boot_start 0: opening snap table
-495> 2019-02-18 21:26:13.561 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6816/2707787 -- osd_op(unknown.0.307:6 4.d 4:b50e409b:::mds_snaptable:head [read 0~0] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108b380 con 0
-494> 2019-02-18 21:26:13.561 7ff42b96e700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6800/2707654 conn(0x55b3910fa000 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-493> 2019-02-18 21:26:13.561 7ff42c16f700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6801/2707522 conn(0x55b39106d800 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-492> 2019-02-18 21:26:13.561 7ff42b16d700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6804/2707580 conn(0x55b3910fae00 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-491> 2019-02-18 21:26:13.561 7ff42c16f700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6814/1907788 conn(0x55b3910fa700 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-490> 2019-02-18 21:26:13.561 7ff42b96e700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6820/2707789 conn(0x55b3910fb500 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-489> 2019-02-18 21:26:13.561 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6804/2707580 conn(0x55b3910fae00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=71 cs=1 l=1). rx osd.1 seq 1 0x55b39108ad00 osd_op_reply(3 400.00000000 [read 0~22] v0'0 uv1 ondisk = 0) v8
-488> 2019-02-18 21:26:13.561 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== osd.1 10.10.0.18:6804/2707580 1 ==== osd_op_reply(3 400.00000000 [read 0~22] v0'0 uv1 ondisk = 0) v8 ==== 156+0+22 (2890560204 0 3825830296) 0x55b39108ad00 con 0x55b3910fae00
-487> 2019-02-18 21:26:13.561 7ff421f73700 1 mds.0.journaler.mdlog(ro) recover start
-486> 2019-02-18 21:26:13.561 7ff421f73700 1 mds.0.journaler.mdlog(ro) read_head
-485> 2019-02-18 21:26:13.561 7ff42b16d700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6816/2707787 conn(0x55b3910fbc00 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-484> 2019-02-18 21:26:13.561 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6801/2707522 conn(0x55b39106d800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=66 cs=1 l=1). rx osd.4 seq 1 0x55b39108a340 osd_op_reply(1 mds0_inotable [read 0~34] v0'0 uv2 ondisk = 0) v8
-483> 2019-02-18 21:26:13.561 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.4 10.10.0.18:6801/2707522 1 ==== osd_op_reply(1 mds0_inotable [read 0~34] v0'0 uv2 ondisk = 0) v8 ==== 157+0+34 (1607703051 0 1695280775) 0x55b39108a340 con 0x55b39106d800
-482> 2019-02-18 21:26:13.561 7ff421f73700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6810/3799921 -- osd_op(unknown.0.307:7 4.14 4:292cf221:::200.00000000:head [read 0~0] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108a000 con 0
-481> 2019-02-18 21:26:13.561 7ff421f73700 4 mds.0.log Waiting for journal 0x200 to recover...
-480> 2019-02-18 21:26:13.561 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6814/1907788 conn(0x55b3910fa700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=24 cs=1 l=1). rx osd.16 seq 1 0x55b39108a340 osd_op_reply(4 500.00000000 [read 0~90] v0'0 uv856 ondisk = 0) v8
-479> 2019-02-18 21:26:13.561 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.16 10.10.0.16:6814/1907788 1 ==== osd_op_reply(4 500.00000000 [read 0~90] v0'0 uv856 ondisk = 0) v8 ==== 156+0+90 (2044258440 0 1660471416) 0x55b39108a340 con 0x55b3910fa700
-478> 2019-02-18 21:26:13.561 7ff423776700 1 mds.0.journaler.pq(ro) _finish_read_head loghead(trim 4194304, expire 5065833, write 5065833, stream_format 1). probing for end of log (from 5065833)...
-477> 2019-02-18 21:26:13.561 7ff423776700 1 mds.0.journaler.pq(ro) probing for end of the log
-476> 2019-02-18 21:26:13.561 7ff423776700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6817/3799922 -- osd_op(unknown.0.307:8 4.1 4:86ee9bce:::500.00000001:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b39108ad00 con 0
-475> 2019-02-18 21:26:13.561 7ff423776700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6820/2707789 -- osd_op(unknown.0.307:9 4.17 4:eaf075c4:::500.00000002:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b39108b380 con 0
-474> 2019-02-18 21:26:13.561 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6816/2707787 conn(0x55b3910fbc00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=79 cs=1 l=1). rx osd.3 seq 1 0x55b39108bd40 osd_op_reply(6 mds_snaptable [read 0~70] v0'0 uv2 ondisk = 0) v8
-473> 2019-02-18 21:26:13.561 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== osd.3 10.10.0.18:6816/2707787 1 ==== osd_op_reply(6 mds_snaptable [read 0~70] v0'0 uv2 ondisk = 0) v8 ==== 157+0+70 (249273192 0 294686788) 0x55b39108bd40 con 0x55b3910fbc00
-472> 2019-02-18 21:26:13.565 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6820/2707789 conn(0x55b3910fb500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=78 cs=1 l=1). rx osd.5 seq 1 0x55b39108b380 osd_op_reply(9 500.00000002 [stat] v0'0 uv0 ondisk = -2 ((2) No such file or directory)) v8
-471> 2019-02-18 21:26:13.565 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.5 10.10.0.18:6820/2707789 1 ==== osd_op_reply(9 500.00000002 [stat] v0'0 uv0 ondisk = -2 ((2) No such file or directory)) v8 ==== 156+0+0 (3762615101 0 0) 0x55b39108b380 con 0x55b3910fb500
-470> 2019-02-18 21:26:13.565 7ff42c16f700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6810/3799921 conn(0x55b3910fca00 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-469> 2019-02-18 21:26:13.565 7ff42b96e700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-468> 2019-02-18 21:26:13.565 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=242 cs=1 l=1). rx osd.18 seq 1 0x55b39108b040 osd_op_reply(8 500.00000001 [stat] v0'0 uv250 ondisk = 0) v8
-467> 2019-02-18 21:26:13.565 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.18 10.10.0.17:6817/3799922 1 ==== osd_op_reply(8 500.00000001 [stat] v0'0 uv250 ondisk = 0) v8 ==== 156+0+16 (780089013 0 716870517) 0x55b39108b040 con 0x55b3910fd800
-466> 2019-02-18 21:26:13.565 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6810/3799921 conn(0x55b3910fca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=248 cs=1 l=1). rx osd.19 seq 1 0x55b39108a000 osd_op_reply(7 200.00000000 [read 0~90] v0'0 uv1553 ondisk = 0) v8
-465> 2019-02-18 21:26:13.565 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.19 10.10.0.17:6810/3799921 1 ==== osd_op_reply(7 200.00000000 [read 0~90] v0'0 uv1553 ondisk = 0) v8 ==== 156+0+90 (3515981314 0 1118927224) 0x55b39108a000 con 0x55b3910fca00
-464> 2019-02-18 21:26:13.565 7ff423776700 1 mds.0.journaler.pq(ro) _finish_probe_end write_pos = 5065833 (header had 5065833). recovered.
-463> 2019-02-18 21:26:13.565 7ff423776700 4 mds.0.purge_queue operator(): open complete
-462> 2019-02-18 21:26:13.565 7ff423776700 1 mds.0.journaler.pq(ro) set_writeable
-461> 2019-02-18 21:26:13.565 7ff422774700 1 mds.0.journaler.mdlog(ro) _finish_read_head loghead(trim 4194304, expire 4194304, write 159638822, stream_format 1). probing for end of log (from 159638822)...
-460> 2019-02-18 21:26:13.565 7ff422774700 1 mds.0.journaler.mdlog(ro) probing for end of the log
-459> 2019-02-18 21:26:13.565 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6817/3799922 -- osd_op(unknown.0.307:10 4.1f 4:fc76fa7d:::200.00000026:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b39108b6c0 con 0
-458> 2019-02-18 21:26:13.565 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6800/2707654 -- osd_op(unknown.0.307:11 4.3 4:c7ae69ec:::200.00000027:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b39108c3c0 con 0
-457> 2019-02-18 21:26:13.565 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=242 cs=1 l=1). rx osd.18 seq 2 0x55b39108ad00 osd_op_reply(10 200.00000026 [stat] v0'0 uv609 ondisk = 0) v8
-456> 2019-02-18 21:26:13.565 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.18 10.10.0.17:6817/3799922 2 ==== osd_op_reply(10 200.00000026 [stat] v0'0 uv609 ondisk = 0) v8 ==== 156+0+16 (678736016 0 3490416101) 0x55b39108ad00 con 0x55b3910fd800
-455> 2019-02-18 21:26:13.565 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6800/2707654 conn(0x55b3910fa000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=97 cs=1 l=1). rx osd.0 seq 1 0x55b39108ad00 osd_op_reply(11 200.00000027 [stat] v0'0 uv0 ondisk = -2 ((2) No such file or directory)) v8
-454> 2019-02-18 21:26:13.565 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.0 10.10.0.18:6800/2707654 1 ==== osd_op_reply(11 200.00000027 [stat] v0'0 uv0 ondisk = -2 ((2) No such file or directory)) v8 ==== 156+0+0 (3219452552 0 0) 0x55b39108ad00 con 0x55b3910fa000
-453> 2019-02-18 21:26:13.565 7ff422774700 1 mds.0.journaler.mdlog(ro) _finish_probe_end write_pos = 159639406 (header had 159638822). recovered.
-452> 2019-02-18 21:26:13.565 7ff421f73700 4 mds.0.log Journal 0x200 recovered.
-451> 2019-02-18 21:26:13.565 7ff421f73700 4 mds.0.log Recovered journal 0x200 in format 1
-450> 2019-02-18 21:26:13.569 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6800/2707654 conn(0x55b3910fa000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=97 cs=1 l=1). rx osd.0 seq 2 0x55b39108ad00 osd_op_reply(2 mds0_sessionmap [omap-get-header,omap-get-vals] v0'0 uv1 ondisk = 0) v8
-449> 2019-02-18 21:26:13.569 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.0 10.10.0.18:6800/2707654 2 ==== osd_op_reply(2 mds0_sessionmap [omap-get-header,omap-get-vals] v0'0 uv1 ondisk = 0) v8 ==== 201+0+19 (26263688 0 1118585302) 0x55b39108ad00 con 0x55b3910fa000
-448> 2019-02-18 21:26:13.569 7ff422774700 2 mds.0.307 boot_start 1: loading/discovering base inodes
-447> 2019-02-18 21:26:13.569 7ff422774700 0 mds.0.cache creating system inode with ino:0x100
-446> 2019-02-18 21:26:13.569 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6801/2707522 -- osd_op(unknown.0.307:12 4.13 4:cd5a64a3:::100.00000000:head [getxattr inode] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108c700 con 0
-445> 2019-02-18 21:26:13.569 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6817/3799922 -- osd_op(unknown.0.307:13 4.1f 4:fe07bba1:::100.00000000.inode:head [read 0~0] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108ca40 con 0
-444> 2019-02-18 21:26:13.569 7ff422774700 0 mds.0.cache creating system inode with ino:0x1
-443> 2019-02-18 21:26:13.569 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6817/3799922 -- osd_op(unknown.0.307:14 4.1f 4:ff5b34d6:::1.00000000:head [getxattr inode] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108cd80 con 0
-442> 2019-02-18 21:26:13.569 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6810/3799921 -- osd_op(unknown.0.307:15 4.14 4:287034c4:::1.00000000.inode:head [read 0~0] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108a9c0 con 0
-441> 2019-02-18 21:26:13.569 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6801/2707522 conn(0x55b39106d800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=66 cs=1 l=1). rx osd.4 seq 2 0x55b39108a9c0 osd_op_reply(12 100.00000000 [getxattr] v0'0 uv0 ondisk = -61 ((61) No data available)) v8
-440> 2019-02-18 21:26:13.569 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.4 10.10.0.18:6801/2707522 2 ==== osd_op_reply(12 100.00000000 [getxattr] v0'0 uv0 ondisk = -61 ((61) No data available)) v8 ==== 156+0+0 (1070477590 0 0) 0x55b39108a9c0 con 0x55b39106d800
-439> 2019-02-18 21:26:13.569 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6810/3799921 conn(0x55b3910fca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=248 cs=1 l=1). rx osd.19 seq 2 0x55b39108a9c0 osd_op_reply(15 1.00000000.inode [read 0~536] v0'0 uv4 ondisk = 0) v8
-438> 2019-02-18 21:26:13.569 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.19 10.10.0.17:6810/3799921 2 ==== osd_op_reply(15 1.00000000.inode [read 0~536] v0'0 uv4 ondisk = 0) v8 ==== 160+0+536 (2560198561 0 1205164707) 0x55b39108a9c0 con 0x55b3910fca00
-437> 2019-02-18 21:26:13.569 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=242 cs=1 l=1). rx osd.18 seq 3 0x55b39108c3c0 osd_op_reply(13 100.00000000.inode [read 0~536] v0'0 uv2 ondisk = 0) v8
-436> 2019-02-18 21:26:13.569 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.18 10.10.0.17:6817/3799922 3 ==== osd_op_reply(13 100.00000000.inode [read 0~536] v0'0 uv2 ondisk = 0) v8 ==== 162+0+536 (159367068 0 2779624372) 0x55b39108c3c0 con 0x55b3910fd800
-435> 2019-02-18 21:26:13.569 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=242 cs=1 l=1). rx osd.18 seq 4 0x55b39108c3c0 osd_op_reply(14 1.00000000 [getxattr] v0'0 uv0 ondisk = -61 ((61) No data available)) v8
-434> 2019-02-18 21:26:13.569 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.18 10.10.0.17:6817/3799922 4 ==== osd_op_reply(14 1.00000000 [getxattr] v0'0 uv0 ondisk = -61 ((61) No data available)) v8 ==== 154+0+0 (2208785262 0 0) 0x55b39108c3c0 con 0x55b3910fd800
-433> 2019-02-18 21:26:13.569 7ff422774700 2 mds.0.307 boot_start 2: replaying mds log
-432> 2019-02-18 21:26:13.569 7ff422774700 2 mds.0.307 boot_start 2: waiting for purge queue recovered
-431> 2019-02-18 21:26:13.569 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6820/2707789 conn(0x55b3910fb500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=78 cs=1 l=1). rx osd.5 seq 2 0x55b39108c3c0 osd_op_reply(5 mds0_openfiles.0 [omap-get-header,omap-get-vals] v0'0 uv555 ondisk = 0) v8
-430> 2019-02-18 21:26:13.569 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.5 10.10.0.18:6820/2707789 2 ==== osd_op_reply(5 mds0_openfiles.0 [omap-get-header,omap-get-vals] v0'0 uv555 ondisk = 0) v8 ==== 202+0+62100 (2820856895 0 3573701468) 0x55b39108c3c0 con 0x55b3910fb500
-429> 2019-02-18 21:26:13.569 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6810/3799921 -- osd_op(unknown.0.307:16 4.14 4:2e2fa760:::200.00000001:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108d0c0 con 0
-428> 2019-02-18 21:26:13.569 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6801/2707522 -- osd_op(unknown.0.307:17 4.1b 4:ddb4e4d7:::200.00000002:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108d400 con 0
-427> 2019-02-18 21:26:13.569 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6800/2707654 -- osd_op(unknown.0.307:18 4.b 4:d5c7a900:::200.00000003:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108d740 con 0
-426> 2019-02-18 21:26:13.569 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6817/3799922 -- osd_op(unknown.0.307:19 4.1f 4:f83d65d8:::200.00000004:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108da80 con 0
-425> 2019-02-18 21:26:13.569 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6805/1907572 -- osd_op(unknown.0.307:20 4.1a 4:5e41ab69:::200.00000005:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b391180000 con 0
-424> 2019-02-18 21:26:13.569 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6814/1907788 -- osd_op(unknown.0.307:21 4.1e 4:7bf7e7b5:::200.00000006:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b391180340 con 0
-423> 2019-02-18 21:26:13.569 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6816/2707787 -- osd_op(unknown.0.307:22 4.1d 4:bec1251c:::200.00000007:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b391180680 con 0
-422> 2019-02-18 21:26:13.569 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6816/2707787 -- osd_op(unknown.0.307:23 4.1d 4:bf8dcf43:::200.00000008:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b3911809c0 con 0
-421> 2019-02-18 21:26:13.569 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6801/2707522 -- osd_op(unknown.0.307:24 4.0 4:02ac1934:::200.00000009:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b391180d00 con 0
-420> 2019-02-18 21:26:13.569 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6801/2707522 -- osd_op(unknown.0.307:25 4.13 4:ceffbd45:::200.0000000a:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b391181040 con 0
-419> 2019-02-18 21:26:13.569 7ff42b16d700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6805/1907572 conn(0x55b39113c300 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-418> 2019-02-18 21:26:13.753 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6814/1907788 conn(0x55b3910fa700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=24 cs=1 l=1). rx osd.16 seq 2 0x55b391181040 osd_op_reply(21 200.00000006 [read 0~4194304 [fadvise_dontneed]] v0'0 uv488 ondisk = 0) v8
-417> 2019-02-18 21:26:13.753 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.16 10.10.0.16:6814/1907788 2 ==== osd_op_reply(21 200.00000006 [read 0~4194304 [fadvise_dontneed]] v0'0 uv488 ondisk = 0) v8 ==== 156+0+4194304 (3661107399 0 2683165417) 0x55b391181040 con 0x55b3910fa700
-416> 2019-02-18 21:26:13.761 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6801/2707522 conn(0x55b39106d800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=66 cs=1 l=1). rx osd.4 seq 3 0x55b391181040 osd_op_reply(17 200.00000002 [read 0~4194304 [fadvise_dontneed]] v0'0 uv594 ondisk = 0) v8
-415> 2019-02-18 21:26:13.761 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.4 10.10.0.18:6801/2707522 3 ==== osd_op_reply(17 200.00000002 [read 0~4194304 [fadvise_dontneed]] v0'0 uv594 ondisk = 0) v8 ==== 156+0+4194304 (1952172549 0 1548361039) 0x55b391181040 con 0x55b39106d800
-414> 2019-02-18 21:26:13.805 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=242 cs=1 l=1). rx osd.18 seq 5 0x55b39108a000 osd_op_reply(19 200.00000004 [read 0~4194304 [fadvise_dontneed]] v0'0 uv492 ondisk = 0) v8
-413> 2019-02-18 21:26:13.805 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.18 10.10.0.17:6817/3799922 5 ==== osd_op_reply(19 200.00000004 [read 0~4194304 [fadvise_dontneed]] v0'0 uv492 ondisk = 0) v8 ==== 156+0+4194304 (2578514724 0 3871202058) 0x55b39108a000 con 0x55b3910fd800
-412> 2019-02-18 21:26:13.833 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6801/2707522 conn(0x55b39106d800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=66 cs=1 l=1). rx osd.4 seq 4 0x55b391181040 osd_op_reply(25 200.0000000a [read 0~4194304 [fadvise_dontneed]] v0'0 uv503 ondisk = 0) v8
-411> 2019-02-18 21:26:13.833 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.4 10.10.0.18:6801/2707522 4 ==== osd_op_reply(25 200.0000000a [read 0~4194304 [fadvise_dontneed]] v0'0 uv503 ondisk = 0) v8 ==== 156+0+4194304 (580133374 0 1413319993) 0x55b391181040 con 0x55b39106d800
-410> 2019-02-18 21:26:13.869 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6810/3799921 conn(0x55b3910fca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=248 cs=1 l=1). rx osd.19 seq 3 0x55b391181040 osd_op_reply(16 200.00000001 [read 0~4194304 [fadvise_dontneed]] v0'0 uv820 ondisk = 0) v8
-409> 2019-02-18 21:26:13.869 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.19 10.10.0.17:6810/3799921 3 ==== osd_op_reply(16 200.00000001 [read 0~4194304 [fadvise_dontneed]] v0'0 uv820 ondisk = 0) v8 ==== 156+0+4194304 (2259551564 0 3684064079) 0x55b391181040 con 0x55b3910fca00
-408> 2019-02-18 21:26:13.869 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6805/1907572 -- osd_op(unknown.0.307:26 4.2 4:4272d415:::200.0000000b:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b391181380 con 0
-407> 2019-02-18 21:26:13.877 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6816/2707787 conn(0x55b3910fbc00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=79 cs=1 l=1). rx osd.3 seq 2 0x55b391181380 osd_op_reply(22 200.00000007 [read 0~4194304 [fadvise_dontneed]] v0'0 uv667 ondisk = 0) v8
-406> 2019-02-18 21:26:13.877 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== osd.3 10.10.0.18:6816/2707787 2 ==== osd_op_reply(22 200.00000007 [read 0~4194304 [fadvise_dontneed]] v0'0 uv667 ondisk = 0) v8 ==== 156+0+4194304 (296147102 0 3874057656) 0x55b391181380 con 0x55b3910fbc00
-405> 2019-02-18 21:26:13.885 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6801/2707522 -- osd_op(unknown.0.307:27 4.0 4:07a02702:::200.0000000c:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b3911816c0 con 0
-404> 2019-02-18 21:26:13.893 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6801/2707522 conn(0x55b39106d800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=66 cs=1 l=1). rx osd.4 seq 5 0x55b3911816c0 osd_op_reply(24 200.00000009 [read 0~4194304 [fadvise_dontneed]] v0'0 uv520 ondisk = 0) v8
-403> 2019-02-18 21:26:13.893 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.4 10.10.0.18:6801/2707522 5 ==== osd_op_reply(24 200.00000009 [read 0~4194304 [fadvise_dontneed]] v0'0 uv520 ondisk = 0) v8 ==== 156+0+4194304 (1590693230 0 1987126615) 0x55b3911816c0 con 0x55b39106d800
-402> 2019-02-18 21:26:13.901 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6805/1907572 conn(0x55b39113c300 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=18 cs=1 l=1). rx osd.15 seq 1 0x55b391181380 osd_op_reply(20 200.00000005 [read 0~4194304 [fadvise_dontneed]] v0'0 uv638 ondisk = 0) v8
-401> 2019-02-18 21:26:13.901 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== osd.15 10.10.0.16:6805/1907572 1 ==== osd_op_reply(20 200.00000005 [read 0~4194304 [fadvise_dontneed]] v0'0 uv638 ondisk = 0) v8 ==== 156+0+4194304 (1886516283 0 540111858) 0x55b391181380 con 0x55b39113c300
-400> 2019-02-18 21:26:13.965 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6801/2707522 conn(0x55b39106d800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=66 cs=1 l=1). rx osd.4 seq 6 0x55b3911816c0 osd_op_reply(27 200.0000000c [read 0~4194304 [fadvise_dontneed]] v0'0 uv1041 ondisk = 0) v8
-399> 2019-02-18 21:26:13.965 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.4 10.10.0.18:6801/2707522 6 ==== osd_op_reply(27 200.0000000c [read 0~4194304 [fadvise_dontneed]] v0'0 uv1041 ondisk = 0) v8 ==== 156+0+4194304 (1977566415 0 521215537) 0x55b3911816c0 con 0x55b39106d800
-398> 2019-02-18 21:26:13.985 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6800/2707654 conn(0x55b3910fa000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=97 cs=1 l=1). rx osd.0 seq 3 0x55b39108a000 osd_op_reply(18 200.00000003 [read 0~4194304 [fadvise_dontneed]] v0'0 uv559 ondisk = 0) v8
-397> 2019-02-18 21:26:13.985 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.0 10.10.0.18:6800/2707654 3 ==== osd_op_reply(18 200.00000003 [read 0~4194304 [fadvise_dontneed]] v0'0 uv559 ondisk = 0) v8 ==== 156+0+4194304 (804170131 0 319518351) 0x55b39108a000 con 0x55b3910fa000
-396> 2019-02-18 21:26:13.985 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6801/2707522 -- osd_op(unknown.0.307:28 4.13 4:cb3d3880:::200.0000000d:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b391181a00 con 0
-395> 2019-02-18 21:26:14.001 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6810/3799921 -- osd_op(unknown.0.307:29 4.18 4:1e8917d7:::200.0000000e:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108b040 con 0
-394> 2019-02-18 21:26:14.001 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6816/2707787 conn(0x55b3910fbc00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=79 cs=1 l=1). rx osd.3 seq 3 0x55b391181380 osd_op_reply(23 200.00000008 [read 0~4194304 [fadvise_dontneed]] v0'0 uv1069 ondisk = 0) v8
-393> 2019-02-18 21:26:14.001 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== osd.3 10.10.0.18:6816/2707787 3 ==== osd_op_reply(23 200.00000008 [read 0~4194304 [fadvise_dontneed]] v0'0 uv1069 ondisk = 0) v8 ==== 156+0+4194304 (2201798201 0 3448329836) 0x55b391181380 con 0x55b3910fbc00
-392> 2019-02-18 21:26:14.017 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6805/1907572 conn(0x55b39113c300 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=18 cs=1 l=1). rx osd.15 seq 2 0x55b391181380 osd_op_reply(26 200.0000000b [read 0~4194304 [fadvise_dontneed]] v0'0 uv514 ondisk = 0) v8
-391> 2019-02-18 21:26:14.017 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== osd.15 10.10.0.16:6805/1907572 2 ==== osd_op_reply(26 200.0000000b [read 0~4194304 [fadvise_dontneed]] v0'0 uv514 ondisk = 0) v8 ==== 156+0+4194304 (138055556 0 1530832353) 0x55b391181380 con 0x55b39113c300
-390> 2019-02-18 21:26:14.017 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6810/3799921 -- osd_op(unknown.0.307:30 4.8 4:17051619:::200.0000000f:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108b6c0 con 0
-389> 2019-02-18 21:26:14.033 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6816/2707787 -- osd_op(unknown.0.307:31 4.d 4:b02ffd62:::200.00000010:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108c3c0 con 0
-388> 2019-02-18 21:26:14.045 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6805/1907572 -- osd_op(unknown.0.307:32 4.2 4:42569fed:::200.00000011:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108d740 con 0
-387> 2019-02-18 21:26:14.049 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6810/3799921 conn(0x55b3910fca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=248 cs=1 l=1). rx osd.19 seq 4 0x55b39108b6c0 osd_op_reply(29 200.0000000e [read 0~4194304 [fadvise_dontneed]] v0'0 uv424 ondisk = 0) v8
-386> 2019-02-18 21:26:14.049 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.19 10.10.0.17:6810/3799921 4 ==== osd_op_reply(29 200.0000000e [read 0~4194304 [fadvise_dontneed]] v0'0 uv424 ondisk = 0) v8 ==== 156+0+4194304 (1595146613 0 1245497462) 0x55b39108b6c0 con 0x55b3910fca00
-385> 2019-02-18 21:26:14.061 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6810/3799921 -- osd_op(unknown.0.307:33 4.18 4:1cc859d9:::200.00000012:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108da80 con 0
-384> 2019-02-18 21:26:14.073 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6805/1907572 -- osd_op(unknown.0.307:34 4.e 4:715f5c78:::200.00000013:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108c080 con 0
-383> 2019-02-18 21:26:14.089 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6810/3799921 -- osd_op(unknown.0.307:35 4.1c 4:3939b497:::200.00000014:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108c3c0 con 0
-382> 2019-02-18 21:26:14.097 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6810/3799921 conn(0x55b3910fca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=248 cs=1 l=1). rx osd.19 seq 5 0x55b39108c3c0 osd_op_reply(30 200.0000000f [read 0~4194304 [fadvise_dontneed]] v0'0 uv430 ondisk = 0) v8
-381> 2019-02-18 21:26:14.097 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.19 10.10.0.17:6810/3799921 5 ==== osd_op_reply(30 200.0000000f [read 0~4194304 [fadvise_dontneed]] v0'0 uv430 ondisk = 0) v8 ==== 156+0+4194304 (130265795 0 1361366437) 0x55b39108c3c0 con 0x55b3910fca00
-380> 2019-02-18 21:26:14.105 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6816/2707787 -- osd_op(unknown.0.307:36 4.1d 4:bec9163d:::200.00000015:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108d740 con 0
-379> 2019-02-18 21:26:14.117 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6804/2707580 -- osd_op(unknown.0.307:37 4.f 4:f376ae95:::200.00000016:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108c080 con 0
-378> 2019-02-18 21:26:14.157 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6810/3799921 conn(0x55b3910fca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=248 cs=1 l=1). rx osd.19 seq 6 0x55b39108c3c0 osd_op_reply(33 200.00000012 [read 0~4194304 [fadvise_dontneed]] v0'0 uv872 ondisk = 0) v8
-377> 2019-02-18 21:26:14.157 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.19 10.10.0.17:6810/3799921 6 ==== osd_op_reply(33 200.00000012 [read 0~4194304 [fadvise_dontneed]] v0'0 uv872 ondisk = 0) v8 ==== 156+0+4194304 (510903308 0 95197740) 0x55b39108c3c0 con 0x55b3910fca00
-376> 2019-02-18 21:26:14.249 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6801/2707522 conn(0x55b39106d800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=66 cs=1 l=1). rx osd.4 seq 7 0x55b39108c3c0 osd_op_reply(28 200.0000000d [read 0~4194304 [fadvise_dontneed]] v0'0 uv1038 ondisk = 0) v8
-375> 2019-02-18 21:26:14.249 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.4 10.10.0.18:6801/2707522 7 ==== osd_op_reply(28 200.0000000d [read 0~4194304 [fadvise_dontneed]] v0'0 uv1038 ondisk = 0) v8 ==== 156+0+4194304 (2994680799 0 3656271960) 0x55b39108c3c0 con 0x55b39106d800
-374> 2019-02-18 21:26:14.249 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6809/1907588 -- osd_op(unknown.0.307:38 4.a 4:545c15c7:::200.00000017:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108b040 con 0
-373> 2019-02-18 21:26:14.253 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6810/3799921 conn(0x55b3910fca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=248 cs=1 l=1). rx osd.19 seq 7 0x55b39108c3c0 osd_op_reply(35 200.00000014 [read 0~4194304 [fadvise_dontneed]] v0'0 uv132 ondisk = 0) v8
-372> 2019-02-18 21:26:14.253 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.19 10.10.0.17:6810/3799921 7 ==== osd_op_reply(35 200.00000014 [read 0~4194304 [fadvise_dontneed]] v0'0 uv132 ondisk = 0) v8 ==== 156+0+4194304 (4212349984 0 887550635) 0x55b39108c3c0 con 0x55b3910fca00
-371> 2019-02-18 21:26:14.253 7ff42c16f700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6809/1907588 conn(0x55b392f0a700 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-370> 2019-02-18 21:26:14.257 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6805/1907572 conn(0x55b39113c300 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=18 cs=1 l=1). rx osd.15 seq 3 0x55b39108c080 osd_op_reply(32 200.00000011 [read 0~4194304 [fadvise_dontneed]] v0'0 uv981 ondisk = 0) v8
-369> 2019-02-18 21:26:14.257 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== osd.15 10.10.0.16:6805/1907572 3 ==== osd_op_reply(32 200.00000011 [read 0~4194304 [fadvise_dontneed]] v0'0 uv981 ondisk = 0) v8 ==== 156+0+4194304 (196457918 0 2217815792) 0x55b39108c080 con 0x55b39113c300
-368> 2019-02-18 21:26:14.265 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6805/1907572 -- osd_op(unknown.0.307:39 4.1a 4:590b566d:::200.00000018:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108b6c0 con 0
-367> 2019-02-18 21:26:14.277 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6800/2707654 -- osd_op(unknown.0.307:40 4.b 4:d2a48755:::200.00000019:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108da80 con 0
-366> 2019-02-18 21:26:14.289 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6816/2707787 conn(0x55b3910fbc00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=79 cs=1 l=1). rx osd.3 seq 4 0x55b39108b6c0 osd_op_reply(31 200.00000010 [read 0~4194304 [fadvise_dontneed]] v0'0 uv463 ondisk = 0) v8
-365> 2019-02-18 21:26:14.289 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== osd.3 10.10.0.18:6816/2707787 4 ==== osd_op_reply(31 200.00000010 [read 0~4194304 [fadvise_dontneed]] v0'0 uv463 ondisk = 0) v8 ==== 156+0+4194304 (57968226 0 2853452776) 0x55b39108b6c0 con 0x55b3910fbc00
-364> 2019-02-18 21:26:14.293 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6810/3799921 -- osd_op(unknown.0.307:41 4.14 4:2e600548:::200.0000001a:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108bd40 con 0
-363> 2019-02-18 21:26:14.309 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6816/2707787 -- osd_op(unknown.0.307:42 4.19 4:9d0ed013:::200.0000001b:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b392bd8000 con 0
-362> 2019-02-18 21:26:14.321 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6820/2707789 -- osd_op(unknown.0.307:43 4.16 4:6b6b4f13:::200.0000001c:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b392bd8340 con 0
-361> 2019-02-18 21:26:14.397 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6804/2707580 conn(0x55b3910fae00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=71 cs=1 l=1). rx osd.1 seq 2 0x55b392bd8000 osd_op_reply(37 200.00000016 [read 0~4194304 [fadvise_dontneed]] v0'0 uv60 ondisk = 0) v8
-360> 2019-02-18 21:26:14.397 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== osd.1 10.10.0.18:6804/2707580 2 ==== osd_op_reply(37 200.00000016 [read 0~4194304 [fadvise_dontneed]] v0'0 uv60 ondisk = 0) v8 ==== 156+0+4194304 (3633744323 0 961424312) 0x55b392bd8000 con 0x55b3910fae00
-359> 2019-02-18 21:26:14.409 7ff42677c700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6800/1906091 -- mgrreport(unknown.sg1vosrv12 +111-0 packed 1374) v6 -- 0x55b390fc9880 con 0
-358> 2019-02-18 21:26:14.417 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6805/1907572 conn(0x55b39113c300 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=18 cs=1 l=1). rx osd.15 seq 4 0x55b392bd8000 osd_op_reply(34 200.00000013 [read 0~4194304 [fadvise_dontneed]] v0'0 uv485 ondisk = 0) v8
-357> 2019-02-18 21:26:14.417 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== osd.15 10.10.0.16:6805/1907572 4 ==== osd_op_reply(34 200.00000013 [read 0~4194304 [fadvise_dontneed]] v0'0 uv485 ondisk = 0) v8 ==== 156+0+4194304 (212543468 0 1608193226) 0x55b392bd8000 con 0x55b39113c300
-356> 2019-02-18 21:26:14.417 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6814/1907788 -- osd_op(unknown.0.307:44 4.5 4:a055a6fb:::200.0000001d:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b392bd8680 con 0
-355> 2019-02-18 21:26:14.421 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6810/3799921 conn(0x55b3910fca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=248 cs=1 l=1). rx osd.19 seq 8 0x55b392bd8680 osd_op_reply(41 200.0000001a [read 0~4194304 [fadvise_dontneed]] v0'0 uv1188 ondisk = 0) v8
-354> 2019-02-18 21:26:14.421 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.19 10.10.0.17:6810/3799921 8 ==== osd_op_reply(41 200.0000001a [read 0~4194304 [fadvise_dontneed]] v0'0 uv1188 ondisk = 0) v8 ==== 156+0+4194304 (1773927172 0 3456838278) 0x55b392bd8680 con 0x55b3910fca00
-353> 2019-02-18 21:26:14.433 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6805/1907572 -- osd_op(unknown.0.307:45 4.1a 4:5d7bf03a:::200.0000001e:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b392bd89c0 con 0
-352> 2019-02-18 21:26:14.473 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6816/2707787 conn(0x55b3910fbc00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=79 cs=1 l=1). rx osd.3 seq 5 0x55b392bd89c0 osd_op_reply(36 200.00000015 [read 0~4194304 [fadvise_dontneed]] v0'0 uv1113 ondisk = 0) v8
-351> 2019-02-18 21:26:14.473 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== osd.3 10.10.0.18:6816/2707787 5 ==== osd_op_reply(36 200.00000015 [read 0~4194304 [fadvise_dontneed]] v0'0 uv1113 ondisk = 0) v8 ==== 156+0+4194304 (2629155759 0 3261265464) 0x55b392bd89c0 con 0x55b3910fbc00
-350> 2019-02-18 21:26:14.477 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6810/3799921 -- osd_op(unknown.0.307:46 4.14 4:2f96a938:::200.0000001f:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b392bd8d00 con 0
-349> 2019-02-18 21:26:14.489 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6814/1907788 -- osd_op(unknown.0.307:47 4.10 4:0a8213bc:::200.00000020:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108ad00 con 0
-348> 2019-02-18 21:26:14.493 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6809/1907588 conn(0x55b392f0a700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=22 cs=1 l=1). rx osd.13 seq 1 0x55b39108ad00 osd_op_reply(38 200.00000017 [read 0~4194304 [fadvise_dontneed]] v0'0 uv32 ondisk = 0) v8
-347> 2019-02-18 21:26:14.493 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.13 10.10.0.16:6809/1907588 1 ==== osd_op_reply(38 200.00000017 [read 0~4194304 [fadvise_dontneed]] v0'0 uv32 ondisk = 0) v8 ==== 156+0+4194304 (937795097 0 2310187829) 0x55b39108ad00 con 0x55b392f0a700
-346> 2019-02-18 21:26:14.505 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6814/1907788 -- osd_op(unknown.0.307:48 4.15 4:ad28d794:::200.00000021:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108ca40 con 0
-345> 2019-02-18 21:26:14.533 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6805/1907572 conn(0x55b39113c300 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=18 cs=1 l=1). rx osd.15 seq 5 0x55b392bd89c0 osd_op_reply(39 200.00000018 [read 0~4194304 [fadvise_dontneed]] v0'0 uv758 ondisk = 0) v8
-344> 2019-02-18 21:26:14.533 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== osd.15 10.10.0.16:6805/1907572 5 ==== osd_op_reply(39 200.00000018 [read 0~4194304 [fadvise_dontneed]] v0'0 uv758 ondisk = 0) v8 ==== 156+0+4194304 (2462302040 0 596529087) 0x55b392bd89c0 con 0x55b39113c300
-343> 2019-02-18 21:26:14.533 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6814/1907788 -- osd_op(unknown.0.307:49 4.10 4:0fe13e98:::200.00000022:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108da80 con 0
-342> 2019-02-18 21:26:14.549 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6800/2707654 conn(0x55b3910fa000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=97 cs=1 l=1). rx osd.0 seq 4 0x55b392bd8680 osd_op_reply(40 200.00000019 [read 0~4194304 [fadvise_dontneed]] v0'0 uv631 ondisk = 0) v8
-341> 2019-02-18 21:26:14.549 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.0 10.10.0.18:6800/2707654 4 ==== osd_op_reply(40 200.00000019 [read 0~4194304 [fadvise_dontneed]] v0'0 uv631 ondisk = 0) v8 ==== 156+0+4194304 (2463962783 0 2613511175) 0x55b392bd8680 con 0x55b3910fa000
-340> 2019-02-18 21:26:14.549 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6801/1907784 -- osd_op(unknown.0.307:50 4.9 4:97c4b052:::200.00000023:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108a000 con 0
-339> 2019-02-18 21:26:14.557 7ff42b96e700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6801/1907784 conn(0x55b394e0d500 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-338> 2019-02-18 21:26:14.565 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6804/2707580 -- osd_op(unknown.0.307:51 4.7 4:e75b9d00:::200.00000024:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108a340 con 0
-337> 2019-02-18 21:26:14.565 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6810/3799921 conn(0x55b3910fca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=248 cs=1 l=1). rx osd.19 seq 9 0x55b39108da80 osd_op_reply(46 200.0000001f [read 0~4194304 [fadvise_dontneed]] v0'0 uv1387 ondisk = 0) v8
-336> 2019-02-18 21:26:14.565 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.19 10.10.0.17:6810/3799921 9 ==== osd_op_reply(46 200.0000001f [read 0~4194304 [fadvise_dontneed]] v0'0 uv1387 ondisk = 0) v8 ==== 156+0+4194304 (1858861219 0 2684703944) 0x55b39108da80 con 0x55b3910fca00
-335> 2019-02-18 21:26:14.613 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6816/2707787 conn(0x55b3910fbc00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=79 cs=1 l=1). rx osd.3 seq 6 0x55b392bd8000 osd_op_reply(42 200.0000001b [read 0~4194304 [fadvise_dontneed]] v0'0 uv117 ondisk = 0) v8
-334> 2019-02-18 21:26:14.613 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== osd.3 10.10.0.18:6816/2707787 6 ==== osd_op_reply(42 200.0000001b [read 0~4194304 [fadvise_dontneed]] v0'0 uv117 ondisk = 0) v8 ==== 156+0+4194304 (2361483139 0 1472165923) 0x55b392bd8000 con 0x55b3910fbc00
-333> 2019-02-18 21:26:14.613 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6801/2707522 -- osd_op(unknown.0.307:52 4.0 4:0582a73f:::200.00000025:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108a9c0 con 0
-332> 2019-02-18 21:26:14.649 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6804/2707580 conn(0x55b3910fae00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=71 cs=1 l=1). rx osd.1 seq 3 0x55b392bd8000 osd_op_reply(51 200.00000024 [read 0~4194304 [fadvise_dontneed]] v0'0 uv272 ondisk = 0) v8
-331> 2019-02-18 21:26:14.649 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== osd.1 10.10.0.18:6804/2707580 3 ==== osd_op_reply(51 200.00000024 [read 0~4194304 [fadvise_dontneed]] v0'0 uv272 ondisk = 0) v8 ==== 156+0+4194304 (3488261155 0 2811236118) 0x55b392bd8000 con 0x55b3910fae00
-330> 2019-02-18 21:26:14.693 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6820/2707789 conn(0x55b3910fb500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=78 cs=1 l=1). rx osd.5 seq 3 0x55b39108a000 osd_op_reply(43 200.0000001c [read 0~4194304 [fadvise_dontneed]] v0'0 uv119 ondisk = 0) v8
-329> 2019-02-18 21:26:14.693 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.5 10.10.0.18:6820/2707789 3 ==== osd_op_reply(43 200.0000001c [read 0~4194304 [fadvise_dontneed]] v0'0 uv119 ondisk = 0) v8 ==== 156+0+4194304 (631748386 0 3037556931) 0x55b39108a000 con 0x55b3910fb500
-328> 2019-02-18 21:26:14.693 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6817/3799922 -- osd_op(unknown.0.307:53 4.1f 4:fc76fa7d:::200.00000026:head [read 0~255854 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b39108d0c0 con 0
-327> 2019-02-18 21:26:14.697 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6801/2707522 conn(0x55b39106d800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=66 cs=1 l=1). rx osd.4 seq 8 0x55b39108a9c0 osd_op_reply(52 200.00000025 [read 0~4194304 [fadvise_dontneed]] v0'0 uv1385 ondisk = 0) v8
-326> 2019-02-18 21:26:14.697 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.4 10.10.0.18:6801/2707522 8 ==== osd_op_reply(52 200.00000025 [read 0~4194304 [fadvise_dontneed]] v0'0 uv1385 ondisk = 0) v8 ==== 156+0+4194304 (1611559293 0 3801290223) 0x55b39108a9c0 con 0x55b39106d800
-325> 2019-02-18 21:26:14.701 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=242 cs=1 l=1). rx osd.18 seq 6 0x55b392bda080 osd_op_reply(53 200.00000026 [read 0~255854 [fadvise_dontneed]] v0'0 uv609 ondisk = 0) v8
-324> 2019-02-18 21:26:14.701 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.18 10.10.0.17:6817/3799922 6 ==== osd_op_reply(53 200.00000026 [read 0~255854 [fadvise_dontneed]] v0'0 uv609 ondisk = 0) v8 ==== 156+0+255854 (2923650612 0 2744562076) 0x55b392bda080 con 0x55b3910fd800
-323> 2019-02-18 21:26:14.745 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6814/1907788 conn(0x55b3910fa700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=24 cs=1 l=1). rx osd.16 seq 3 0x55b39108a9c0 osd_op_reply(44 200.0000001d [read 0~4194304 [fadvise_dontneed]] v0'0 uv66 ondisk = 0) v8
-322> 2019-02-18 21:26:14.745 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.16 10.10.0.16:6814/1907788 3 ==== osd_op_reply(44 200.0000001d [read 0~4194304 [fadvise_dontneed]] v0'0 uv66 ondisk = 0) v8 ==== 156+0+4194304 (1250259555 0 3208044187) 0x55b39108a9c0 con 0x55b3910fa700
-321> 2019-02-18 21:26:14.781 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6814/1907788 conn(0x55b3910fa700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=24 cs=1 l=1). rx osd.16 seq 4 0x55b39108a9c0 osd_op_reply(47 200.00000020 [read 0~4194304 [fadvise_dontneed]] v0'0 uv112 ondisk = 0) v8
-320> 2019-02-18 21:26:14.781 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.16 10.10.0.16:6814/1907788 4 ==== osd_op_reply(47 200.00000020 [read 0~4194304 [fadvise_dontneed]] v0'0 uv112 ondisk = 0) v8 ==== 156+0+4194304 (1548338078 0 850944195) 0x55b39108a9c0 con 0x55b3910fa700
-319> 2019-02-18 21:26:14.945 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6814/1907788 conn(0x55b3910fa700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=24 cs=1 l=1). rx osd.16 seq 5 0x55b39108a9c0 osd_op_reply(48 200.00000021 [read 0~4194304 [fadvise_dontneed]] v0'0 uv819 ondisk = 0) v8
-318> 2019-02-18 21:26:14.945 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.16 10.10.0.16:6814/1907788 5 ==== osd_op_reply(48 200.00000021 [read 0~4194304 [fadvise_dontneed]] v0'0 uv819 ondisk = 0) v8 ==== 156+0+4194304 (2789436446 0 241370641) 0x55b39108a9c0 con 0x55b3910fa700
-317> 2019-02-18 21:26:14.985 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6801/1907784 conn(0x55b394e0d500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=25 cs=1 l=1). rx osd.14 seq 1 0x55b392bda080 osd_op_reply(50 200.00000023 [read 0~4194304 [fadvise_dontneed]] v0'0 uv304 ondisk = 0) v8
-316> 2019-02-18 21:26:14.985 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.14 10.10.0.16:6801/1907784 1 ==== osd_op_reply(50 200.00000023 [read 0~4194304 [fadvise_dontneed]] v0'0 uv304 ondisk = 0) v8 ==== 156+0+4194304 (706361563 0 701741253) 0x55b392bda080 con 0x55b394e0d500
-315> 2019-02-18 21:26:15.021 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6814/1907788 conn(0x55b3910fa700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=24 cs=1 l=1). rx osd.16 seq 6 0x55b39108a9c0 osd_op_reply(49 200.00000022 [read 0~4194304 [fadvise_dontneed]] v0'0 uv293 ondisk = 0) v8
-314> 2019-02-18 21:26:15.021 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.16 10.10.0.16:6814/1907788 6 ==== osd_op_reply(49 200.00000022 [read 0~4194304 [fadvise_dontneed]] v0'0 uv293 ondisk = 0) v8 ==== 156+0+4194304 (4110978049 0 2473970219) 0x55b39108a9c0 con 0x55b3910fa700
-313> 2019-02-18 21:26:15.033 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6805/1907572 conn(0x55b39113c300 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=18 cs=1 l=1). rx osd.15 seq 6 0x55b392bd8000 osd_op_reply(45 200.0000001e [read 0~4194304 [fadvise_dontneed]] v0'0 uv1085 ondisk = 0) v8
-312> 2019-02-18 21:26:15.033 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== osd.15 10.10.0.16:6805/1907572 6 ==== osd_op_reply(45 200.0000001e [read 0~4194304 [fadvise_dontneed]] v0'0 uv1085 ondisk = 0) v8 ==== 156+0+4194304 (3530308700 0 1940880364) 0x55b392bd8000 con 0x55b39113c300
-311> 2019-02-18 21:26:15.101 7ff420f71700 0 log_channel(cluster) log [WRN] : replayed op client.18359173:903,900 used ino 0x100000051bd but session next is 0x10000004bde
-310> 2019-02-18 21:26:15.101 7ff420f71700 0 log_channel(cluster) log [WRN] : replayed op client.18359173:904,900 used ino 0x100000051be but session next is 0x10000004bde
-309> 2019-02-18 21:26:15.101 7ff420f71700 0 log_channel(cluster) log [WRN] : replayed op client.18359173:905,900 used ino 0x100000051bf but session next is 0x10000004bde
-308> 2019-02-18 21:26:15.101 7ff420f71700 0 log_channel(cluster) log [WRN] : replayed op client.18359173:906,900 used ino 0x100000051c0 but session next is 0x10000004bde
-307> 2019-02-18 21:26:15.173 7ff420f71700 1 mds.0.307 replay_done
-306> 2019-02-18 21:26:15.173 7ff420f71700 1 mds.0.307 making mds journal writeable
-305> 2019-02-18 21:26:15.173 7ff420f71700 1 mds.0.journaler.mdlog(ro) set_writeable
-304> 2019-02-18 21:26:15.173 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6817/3799922 -- osd_op(unknown.0.307:54 4.1f 4:fc76fa7d:::200.00000026:head [zero 255854~3938450] snapc 0=[] ondisk+write+known_if_redirected+full_force e87591) v8 -- 0x55b392bda3c0 con 0
-303> 2019-02-18 21:26:15.173 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6800/2707654 -- osd_op(unknown.0.307:55 4.3 4:c7ae69ec:::200.00000027:head [delete] snapc 0=[] ondisk+write+known_if_redirected+full_force e87591) v8 -- 0x55b392bda700 con 0
-302> 2019-02-18 21:26:15.173 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6813/1907634 -- osd_op(unknown.0.307:56 4.4 4:21ec450a:::200.00000028:head [delete] snapc 0=[] ondisk+write+known_if_redirected+full_force e87591) v8 -- 0x55b392bdaa40 con 0
-301> 2019-02-18 21:26:15.173 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.16:6814/1907788 -- osd_op(unknown.0.307:57 4.5 4:a4bdc6a1:::200.00000029:head [delete] snapc 0=[] ondisk+write+known_if_redirected+full_force e87591) v8 -- 0x55b392bdad80 con 0
-300> 2019-02-18 21:26:15.173 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6810/3799921 -- osd_op(unknown.0.307:58 4.18 4:1cd92fda:::200.0000002a:head [delete] snapc 0=[] ondisk+write+known_if_redirected+full_force e87591) v8 -- 0x55b392bdb0c0 con 0
-299> 2019-02-18 21:26:15.173 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6810/3799921 -- osd_op(unknown.0.307:59 4.c 4:372dc315:::200.0000002b:head [delete] snapc 0=[] ondisk+write+known_if_redirected+full_force e87591) v8 -- 0x55b392bdb400 con 0
-298> 2019-02-18 21:26:15.173 7ff420f71700 2 mds.0.307 i am alone, moving to state reconnect
-297> 2019-02-18 21:26:15.173 7ff420f71700 3 mds.0.307 request_state up:reconnect
-296> 2019-02-18 21:26:15.173 7ff420f71700 5 mds.beacon.sg1vosrv12 set_want_state: up:replay -> up:reconnect
-295> 2019-02-18 21:26:15.173 7ff420f71700 5 mds.beacon.sg1vosrv12 Sending beacon up:reconnect seq 3
-294> 2019-02-18 21:26:15.173 7ff420f71700 10 monclient: _send_mon_message to mon.12 at 10.10.0.17:6789/0
-293> 2019-02-18 21:26:15.173 7ff420f71700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6789/0 -- mdsbeacon(18579226/sg1vosrv12 up:reconnect seq 3 v307) v7 -- 0x55b390fc8e00 con 0
-292> 2019-02-18 21:26:15.177 7ff42b16d700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6813/1907634 conn(0x55b394972000 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-291> 2019-02-18 21:26:15.185 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=242 cs=1 l=1). rx osd.18 seq 7 0x55b392bd8680 osd_op_reply(54 200.00000026 [zero 255854~3938450] v87591'610 uv609 ondisk = 0) v8
-290> 2019-02-18 21:26:15.185 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.18 10.10.0.17:6817/3799922 7 ==== osd_op_reply(54 200.00000026 [zero 255854~3938450] v87591'610 uv609 ondisk = 0) v8 ==== 156+0+0 (2001465094 0 0) 0x55b392bd8680 con 0x55b3910fd800
-289> 2019-02-18 21:26:15.201 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6813/1907634 conn(0x55b394972000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=17 cs=1 l=1). rx osd.17 seq 1 0x55b392bdaa40 osd_op_reply(56 200.00000028 [delete] v87591'51 uv0 ondisk = -2 ((2) No such file or directory)) v8
-288> 2019-02-18 21:26:15.201 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== osd.17 10.10.0.16:6813/1907634 1 ==== osd_op_reply(56 200.00000028 [delete] v87591'51 uv0 ondisk = -2 ((2) No such file or directory)) v8 ==== 156+0+0 (3646785643 0 0) 0x55b392bdaa40 con 0x55b394972000
-287> 2019-02-18 21:26:15.209 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6800/2707654 conn(0x55b3910fa000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=97 cs=1 l=1). rx osd.0 seq 5 0x55b392bd8680 osd_op_reply(55 200.00000027 [delete] v87591'42 uv0 ondisk = -2 ((2) No such file or directory)) v8
-286> 2019-02-18 21:26:15.209 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.0 10.10.0.18:6800/2707654 5 ==== osd_op_reply(55 200.00000027 [delete] v87591'42 uv0 ondisk = -2 ((2) No such file or directory)) v8 ==== 156+0+0 (4043151915 0 0) 0x55b392bd8680 con 0x55b3910fa000
-285> 2019-02-18 21:26:15.221 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6810/3799921 conn(0x55b3910fca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=248 cs=1 l=1). rx osd.19 seq 10 0x55b392bdb400 osd_op_reply(59 200.0000002b [delete] v87591'46 uv0 ondisk = -2 ((2) No such file or directory)) v8
-284> 2019-02-18 21:26:15.221 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.19 10.10.0.17:6810/3799921 10 ==== osd_op_reply(59 200.0000002b [delete] v87591'46 uv0 ondisk = -2 ((2) No such file or directory)) v8 ==== 156+0+0 (1160991270 0 0) 0x55b392bdb400 con 0x55b3910fca00
-283> 2019-02-18 21:26:15.241 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.16:6814/1907788 conn(0x55b3910fa700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=24 cs=1 l=1). rx osd.16 seq 7 0x55b392bdb400 osd_op_reply(57 200.00000029 [delete] v87591'112 uv66 ondisk = -2 ((2) No such file or directory)) v8
-282> 2019-02-18 21:26:15.241 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.16 10.10.0.16:6814/1907788 7 ==== osd_op_reply(57 200.00000029 [delete] v87591'112 uv66 ondisk = -2 ((2) No such file or directory)) v8 ==== 156+0+0 (2774531771 0 0) 0x55b392bdb400 con 0x55b3910fa700
-281> 2019-02-18 21:26:15.253 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6810/3799921 conn(0x55b3910fca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=248 cs=1 l=1). rx osd.19 seq 11 0x55b392bdb400 osd_op_reply(58 200.0000002a [delete] v87591'922 uv872 ondisk = -2 ((2) No such file or directory)) v8
-280> 2019-02-18 21:26:15.253 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.19 10.10.0.17:6810/3799921 11 ==== osd_op_reply(58 200.0000002a [delete] v87591'922 uv872 ondisk = -2 ((2) No such file or directory)) v8 ==== 156+0+0 (990842824 0 0) 0x55b392bdb400 con 0x55b3910fca00
-279> 2019-02-18 21:26:15.929 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 >> - conn(0x55b39106a000 :6800 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=38 -
-278> 2019-02-18 21:26:15.929 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 >> - conn(0x55b396106e00 :6800 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=39 -
-277> 2019-02-18 21:26:15.933 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 >> - conn(0x55b39611c000 :6800 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=41 -
-276> 2019-02-18 21:26:15.933 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 >> - conn(0x55b3960bdc00 :6800 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=40 -
-275> 2019-02-18 21:26:15.933 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 >> - conn(0x55b39610d100 :6800 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=42 -
-274> 2019-02-18 21:26:15.933 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 >> - conn(0x55b396102e00 :6800 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=43 -
-273> 2019-02-18 21:26:15.949 7ff42b96e700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.181.15:0/72759821 conn(0x55b396106e00 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=33 cs=1 l=0).handle_connect_msg accept write reply msg done
-272> 2019-02-18 21:26:15.949 7ff42c16f700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.181.17:0/3643175079 conn(0x55b3960bdc00 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=35 cs=1 l=0).handle_connect_msg accept write reply msg done
-271> 2019-02-18 21:26:15.949 7ff42b16d700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/742284117 conn(0x55b39610d100 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=34 cs=1 l=0).handle_connect_msg accept write reply msg done
-270> 2019-02-18 21:26:15.949 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 14 0x55b390fd8f00 mdsmap(e 308) v1
-269> 2019-02-18 21:26:15.949 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 15 0x55b390fc8e00 mdsbeacon(18579226/sg1vosrv12 up:reconnect seq 3 v308) v7
-268> 2019-02-18 21:26:15.949 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 15 ==== mdsbeacon(18579226/sg1vosrv12 up:reconnect seq 3 v308) v7 ==== 135+0+0 (1337954882 0 0) 0x55b390fc8e00 con 0x55b39106b500
-267> 2019-02-18 21:26:15.949 7ff42b96e700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.181.17:0/875193457 conn(0x55b39611c000 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=45 cs=1 l=0).handle_connect_msg accept write reply msg done
-266> 2019-02-18 21:26:15.949 7ff42b16d700 5 mds.beacon.sg1vosrv12 received beacon reply up:reconnect seq 3 rtt 0.776006
-265> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 14 ==== mdsmap(e 308) v1 ==== 657+0+0 (694488824 0 0) 0x55b390fd8f00 con 0x55b39106b500
-264> 2019-02-18 21:26:15.949 7ff429169700 1 mds.sg1vosrv12 Updating MDS map to version 308 from mon.1
-263> 2019-02-18 21:26:15.949 7ff42c16f700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.181.18:0/1459513868 conn(0x55b39106a000 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=37 cs=1 l=0).handle_connect_msg accept write reply msg done
-262> 2019-02-18 21:26:15.949 7ff429169700 1 mds.0.307 handle_mds_map i am now mds.0.307
-261> 2019-02-18 21:26:15.949 7ff429169700 1 mds.0.307 handle_mds_map state change up:replay --> up:reconnect
-260> 2019-02-18 21:26:15.949 7ff42b16d700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/742284117 conn(0x55b39610d100 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=34 cs=1 l=0)._process_connection accept get newly_acked_seq 0
-259> 2019-02-18 21:26:15.949 7ff429169700 1 mds.0.307 reconnect_start
-258> 2019-02-18 21:26:15.949 7ff429169700 1 mds.0.307 reopen_log
-257> 2019-02-18 21:26:15.949 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/742284117 conn(0x55b39610d100 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=34 cs=1 l=0). rx client.15227693 seq 1 0x55b390db8880 client_reconnect(1 caps) v3
-256> 2019-02-18 21:26:15.949 7ff429169700 4 mds.0.307 reconnect_start: killed 0 blacklisted sessions (38 blacklist entries, 10)
-255> 2019-02-18 21:26:15.949 7ff429169700 1 mds.0.server reconnect_clients -- 10 sessions
-254> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 _send_message--> mds.0 10.10.32.124:6800/3814621597 -- mds_table_request(snaptable server_ready) v1 -- ?+0 0x55b390db8ac0
-253> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.32.124:6800/3814621597 -- mds_table_request(snaptable server_ready) v1 -- 0x55b390db8ac0 con 0
-252> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.15227693 10.10.181.16:0/742284117 1 ==== client_reconnect(1 caps) v3 ==== 0+0+98 (0 0 4087271296) 0x55b390db8880 con 0x55b39610d100
-251> 2019-02-18 21:26:15.949 7ff42b96e700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.181.15:0/72759821 conn(0x55b396106e00 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=33 cs=1 l=0)._process_connection accept get newly_acked_seq 0
-250> 2019-02-18 21:26:15.949 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.15:0/72759821 conn(0x55b396106e00 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=33 cs=1 l=0). rx client.15258971 seq 1 0x55b390db9600 client_reconnect(1 caps) v3
-249> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mds.0 10.10.32.124:6800/3814621597 0 ==== mds_table_request(snaptable server_ready) v1 ==== 0+0+0 (0 0 0) 0x55b390db8ac0 con 0x55b39106ae00
-248> 2019-02-18 21:26:15.949 7ff42c16f700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/3015216276 conn(0x55b396102e00 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=42 cs=1 l=0).handle_connect_msg accept write reply msg done
-247> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 _send_message--> mds.0 10.10.32.124:6800/3814621597 -- mds_table_request(snaptable query 1 9 bytes) v1 -- ?+0 0x55b390db8d00
-246> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.32.124:6800/3814621597 -- mds_table_request(snaptable query 1 9 bytes) v1 -- 0x55b390db8d00 con 0
-245> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.15258971 10.10.181.15:0/72759821 1 ==== client_reconnect(1 caps) v3 ==== 0+0+98 (0 0 1486438467) 0x55b390db9600 con 0x55b396106e00
-244> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mds.0 10.10.32.124:6800/3814621597 0 ==== mds_table_request(snaptable query 1 9 bytes) v1 ==== 0+0+0 (0 0 0) 0x55b390db8d00 con 0x55b39106ae00
-243> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.32.124:6800/3814621597 -- mds_table_request(snaptable query_reply 1 tid 1 29 bytes) v1 -- 0x55b390db8ac0 con 0
-242> 2019-02-18 21:26:15.949 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 >> - conn(0x55b396102000 :6800 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=44 -
-241> 2019-02-18 21:26:15.949 7ff42b96e700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.181.17:0/875193457 conn(0x55b39611c000 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=45 cs=1 l=0)._process_connection accept get newly_acked_seq 0
-240> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mds.0 10.10.32.124:6800/3814621597 0 ==== mds_table_request(snaptable query_reply 1 tid 1 29 bytes) v1 ==== 0+0+0 (0 0 0) 0x55b390db8ac0 con 0x55b39106ae00
-239> 2019-02-18 21:26:15.949 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.17:0/875193457 conn(0x55b39611c000 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=45 cs=1 l=0). rx client.18164119 seq 1 0x55b390db8f40 client_reconnect(1 caps) v3
-238> 2019-02-18 21:26:15.949 7ff42c16f700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.181.17:0/3643175079 conn(0x55b3960bdc00 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=35 cs=1 l=0)._process_connection accept get newly_acked_seq 0
-237> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.16:0/742284117 -- client_session(open) v3 -- 0x55b390db8d00 con 0
-236> 2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.15227693 10.10.181.16:0/742284117 after 0.000405
-235> 2019-02-18 21:26:15.949 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 >> - conn(0x55b3960d0000 :6800 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=47 -
-234> 2019-02-18 21:26:15.949 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.17:0/3643175079 conn(0x55b3960bdc00 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=35 cs=1 l=0). rx client.17592384 seq 1 0x55b392bdb400 client_request(client.17592384:659 lookup #0x10000000009/lock_yBgMBwiR 2019-02-18 20:37:27.949525 RETRY=30 caller_uid=33, caller_gid=33{}) v2
-233> 2019-02-18 21:26:15.949 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 >> - conn(0x55b3960d2300 :6800 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=46 -
-232> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.15:0/72759821 -- client_session(open) v3 -- 0x55b390db8880 con 0
-231> 2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.15258971 10.10.181.15:0/72759821 after 0.000475
-230> 2019-02-18 21:26:15.949 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.17:0/3643175079 conn(0x55b3960bdc00 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=35 cs=1 l=0). rx client.17592384 seq 2 0x55b392bdb0c0 client_request(client.17592384:660 lookup #0x10000000009/lock_yBgMBwiR 2019-02-18 20:37:43.617901 RETRY=29 caller_uid=0, caller_gid=0{}) v2
-229> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.18164119 10.10.181.17:0/875193457 1 ==== client_reconnect(1 caps) v3 ==== 0+0+98 (0 0 2545327098) 0x55b390db8f40 con 0x55b39611c000
-228> 2019-02-18 21:26:15.949 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.17:0/3643175079 conn(0x55b3960bdc00 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=35 cs=1 l=0). rx client.17592384 seq 3 0x55b390db9cc0 client_reconnect(1 caps) v3
-227> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.17:0/875193457 -- client_session(open) v3 -- 0x55b390db8ac0 con 0
-226> 2019-02-18 21:26:15.949 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 >> - conn(0x55b3960d2a00 :6800 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=45 -
-225> 2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.18164119 10.10.181.17:0/875193457 after 0.000545
-224> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.17592384 10.10.181.17:0/3643175079 1 ==== client_request(client.17592384:659 lookup #0x10000000009/lock_yBgMBwiR 2019-02-18 20:37:27.949525 RETRY=30 caller_uid=33, caller_gid=33{}) v2 ==== 135+0+0 (2533144350 0 0) 0x55b392bdb400 con 0x55b3960bdc00
-223> 2019-02-18 21:26:15.949 7ff42c16f700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.181.18:0/1459513868 conn(0x55b39106a000 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=37 cs=1 l=0)._process_connection accept get newly_acked_seq 0
-222> 2019-02-18 21:26:15.949 7ff429169700 3 mds.0.server not active yet, waiting
-221> 2019-02-18 21:26:15.949 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.18:0/1459513868 conn(0x55b39106a000 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=37 cs=1 l=0). rx client.17492882 seq 1 0x55b392bdad80 client_request(client.17492882:26 lookup #0x10000000009/lock_yBgMBwiR 2019-02-18 20:37:28.578641 RETRY=30 caller_uid=33, caller_gid=33{}) v2
-220> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.17592384 10.10.181.17:0/3643175079 2 ==== client_request(client.17592384:660 lookup #0x10000000009/lock_yBgMBwiR 2019-02-18 20:37:43.617901 RETRY=29 caller_uid=0, caller_gid=0{}) v2 ==== 135+0+0 (1963562447 0 0) 0x55b392bdb0c0 con 0x55b3960bdc00
-219> 2019-02-18 21:26:15.949 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.18:0/1459513868 conn(0x55b39106a000 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=37 cs=1 l=0). rx client.17492882 seq 2 0x55b39108a9c0 client_request(client.17492882:27 lookup #0x10000000009/lock_yBgMBwiR 2019-02-18 20:37:44.251014 RETRY=28 caller_uid=0, caller_gid=0{}) v2
-218> 2019-02-18 21:26:15.949 7ff429169700 3 mds.0.server not active yet, waiting
-217> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.17592384 10.10.181.17:0/3643175079 3 ==== client_reconnect(1 caps) v3 ==== 0+0+98 (0 0 2836255815) 0x55b390db9cc0 con 0x55b3960bdc00
-216> 2019-02-18 21:26:15.949 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.18:0/1459513868 conn(0x55b39106a000 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=37 cs=1 l=0). rx client.17492882 seq 3 0x55b3932e0000 client_reconnect(1 caps) v3
-215> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.17:0/3643175079 -- client_session(open) v3 -- 0x55b390db8f40 con 0
-214> 2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.17592384 10.10.181.17:0/3643175079 after 0.000841
-213> 2019-02-18 21:26:15.949 7ff42c16f700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/3015216276 conn(0x55b396102e00 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=42 cs=1 l=0)._process_connection accept get newly_acked_seq 0
-212> 2019-02-18 21:26:15.949 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/3015216276 conn(0x55b396102e00 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=42 cs=1 l=0). rx client.18110760 seq 1 0x55b3932e0240 client_reconnect(1 caps) v3
-211> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.17492882 10.10.181.18:0/1459513868 1 ==== client_request(client.17492882:26 lookup #0x10000000009/lock_yBgMBwiR 2019-02-18 20:37:28.578641 RETRY=30 caller_uid=33, caller_gid=33{}) v2 ==== 135+0+0 (4285055920 0 0) 0x55b392bdad80 con 0x55b39106a000
-210> 2019-02-18 21:26:15.949 7ff42b16d700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.32.124:0/3176739197 conn(0x55b396102000 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=34 cs=1 l=0).handle_connect_msg accept write reply msg done
-209> 2019-02-18 21:26:15.949 7ff429169700 3 mds.0.server not active yet, waiting
-208> 2019-02-18 21:26:15.949 7ff42b16d700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.32.124:0/3176739197 conn(0x55b396102000 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=34 cs=1 l=0)._process_connection accept get newly_acked_seq 0
-207> 2019-02-18 21:26:15.949 7ff42c16f700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.181.15:0/536186448 conn(0x55b3960d2a00 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=35 cs=1 l=0).handle_connect_msg accept write reply msg done
-206> 2019-02-18 21:26:15.949 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.32.124:0/3176739197 conn(0x55b396102000 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=34 cs=1 l=0). rx client.18355462 seq 1 0x55b390db8640 client_reconnect(3 caps) v3
-205> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.17492882 10.10.181.18:0/1459513868 2 ==== client_request(client.17492882:27 lookup #0x10000000009/lock_yBgMBwiR 2019-02-18 20:37:44.251014 RETRY=28 caller_uid=0, caller_gid=0{}) v2 ==== 135+0+0 (3895005314 0 0) 0x55b39108a9c0 con 0x55b39106a000
-204> 2019-02-18 21:26:15.949 7ff42b96e700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/4010683472 conn(0x55b3960d2300 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=117 cs=1 l=0).handle_connect_msg accept write reply msg done
-203> 2019-02-18 21:26:15.949 7ff429169700 3 mds.0.server not active yet, waiting
-202> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.18110760 10.10.181.16:0/3015216276 1 ==== client_reconnect(1 caps) v3 ==== 0+0+98 (0 0 785616217) 0x55b3932e0240 con 0x55b396102e00
-201> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.16:0/3015216276 -- client_session(open) v3 -- 0x55b390db9cc0 con 0
-200> 2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.18110760 10.10.181.16:0/3015216276 after 0.001458
-199> 2019-02-18 21:26:15.949 7ff42b16d700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/2022917557 conn(0x55b3960d0000 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=47 cs=1 l=0).handle_connect_msg accept write reply msg done
-198> 2019-02-18 21:26:15.949 7ff42c16f700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.181.15:0/536186448 conn(0x55b3960d2a00 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=35 cs=1 l=0)._process_connection accept get newly_acked_seq 0
-197> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.18355462 10.10.32.124:0/3176739197 1 ==== client_reconnect(3 caps) v3 ==== 0+0+305 (0 0 4010408309) 0x55b390db8640 con 0x55b396102000
-196> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.32.124:0/3176739197 -- client_session(open) v3 -- 0x55b3932e0240 con 0
-195> 2019-02-18 21:26:15.949 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.15:0/536186448 conn(0x55b3960d2a00 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=35 cs=1 l=0). rx client.16348230 seq 1 0x55b3932e0480 client_reconnect(1 caps) v3
-194> 2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.18355462 10.10.32.124:0/3176739197 after 0.001534
-193> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.17492882 10.10.181.18:0/1459513868 3 ==== client_reconnect(1 caps) v3 ==== 0+0+98 (0 0 448879190) 0x55b3932e0000 con 0x55b39106a000
-192> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.18:0/1459513868 -- client_session(open) v3 -- 0x55b390db8640 con 0
-191> 2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.17492882 10.10.181.18:0/1459513868 after 0.001623
-190> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.16348230 10.10.181.15:0/536186448 1 ==== client_reconnect(1 caps) v3 ==== 0+0+98 (0 0 3092427817) 0x55b3932e0480 con 0x55b3960d2a00
-189> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.15:0/536186448 -- client_session(open) v3 -- 0x55b3932e0000 con 0
-188> 2019-02-18 21:26:15.949 7ff42b96e700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/4010683472 conn(0x55b3960d2300 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=117 cs=1 l=0)._process_connection accept get newly_acked_seq 0
-187> 2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.16348230 10.10.181.15:0/536186448 after 0.001670
-186> 2019-02-18 21:26:15.949 7ff42b16d700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/2022917557 conn(0x55b3960d0000 :6800 s=STATE_ACCEPTING_WAIT_SEQ pgs=47 cs=1 l=0)._process_connection accept get newly_acked_seq 0
-185> 2019-02-18 21:26:15.949 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/2022917557 conn(0x55b3960d0000 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=47 cs=1 l=0). rx client.18337740 seq 1 0x55b3932e0b40 client_reconnect(1 caps) v3
-184> 2019-02-18 21:26:15.949 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/4010683472 conn(0x55b3960d2300 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=0). rx client.16348125 seq 1 0x55b392bd8680 client_request(client.16348125:7929 lookup #0x10000003062/settings 2019-02-18 20:37:27.747910 RETRY=30 caller_uid=33, caller_gid=33{}) v2
-183> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.18337740 10.10.181.16:0/2022917557 1 ==== client_reconnect(1 caps) v3 ==== 0+0+98 (0 0 1319804202) 0x55b3932e0b40 con 0x55b3960d0000
-182> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.16:0/2022917557 -- client_session(open) v3 -- 0x55b3932e0480 con 0
-181> 2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.18337740 10.10.181.16:0/2022917557 after 0.001888
-180> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.16348125 10.10.181.16:0/4010683472 1 ==== client_request(client.16348125:7929 lookup #0x10000003062/settings 2019-02-18 20:37:27.747910 RETRY=30 caller_uid=33, caller_gid=33{}) v2 ==== 130+0+0 (4254920922 0 0) 0x55b392bd8680 con 0x55b3960d2300
-179> 2019-02-18 21:26:15.949 7ff429169700 3 mds.0.server not active yet, waiting
-178> 2019-02-18 21:26:15.949 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/4010683472 conn(0x55b3960d2300 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=0). rx client.16348125 seq 2 0x55b392bd8d00 client_request(client.16348125:7930 lookup #0x10000003062/settings 2019-02-18 20:38:04.068523 RETRY=28 caller_uid=33, caller_gid=33{}) v2
-177> 2019-02-18 21:26:15.949 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/4010683472 conn(0x55b3960d2300 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=0). rx client.16348125 seq 3 0x55b392bd96c0 client_request(client.16348125:7931 lookup #0x10000003062/settings 2019-02-18 20:38:04.068523 RETRY=28 caller_uid=33, caller_gid=33{}) v2
-176> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.16348125 10.10.181.16:0/4010683472 2 ==== client_request(client.16348125:7930 lookup #0x10000003062/settings 2019-02-18 20:38:04.068523 RETRY=28 caller_uid=33, caller_gid=33{}) v2 ==== 130+0+0 (3754419499 0 0) 0x55b392bd8d00 con 0x55b3960d2300
-175> 2019-02-18 21:26:15.949 7ff429169700 3 mds.0.server not active yet, waiting
-174> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.16348125 10.10.181.16:0/4010683472 3 ==== client_request(client.16348125:7931 lookup #0x10000003062/settings 2019-02-18 20:38:04.068523 RETRY=28 caller_uid=33, caller_gid=33{}) v2 ==== 130+0+0 (3754419499 0 0) 0x55b392bd96c0 con 0x55b3960d2300
-173> 2019-02-18 21:26:15.949 7ff429169700 3 mds.0.server not active yet, waiting
-172> 2019-02-18 21:26:15.949 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/4010683472 conn(0x55b3960d2300 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=0). rx client.16348125 seq 4 0x55b392bd9380 client_request(client.16348125:7932 lookup #0x10000003062/settings 2019-02-18 20:38:04.068523 RETRY=28 caller_uid=33, caller_gid=33{}) v2
-171> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.16348125 10.10.181.16:0/4010683472 4 ==== client_request(client.16348125:7932 lookup #0x10000003062/settings 2019-02-18 20:38:04.068523 RETRY=28 caller_uid=33, caller_gid=33{}) v2 ==== 130+0+0 (3754419499 0 0) 0x55b392bd9380 con 0x55b3960d2300
-170> 2019-02-18 21:26:15.949 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/4010683472 conn(0x55b3960d2300 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=0). rx client.16348125 seq 5 0x55b392bd9040 client_request(client.16348125:7933 lookup #0x10000003062/settings 2019-02-18 20:38:04.068523 RETRY=28 caller_uid=33, caller_gid=33{}) v2
-169> 2019-02-18 21:26:15.949 7ff429169700 3 mds.0.server not active yet, waiting
-168> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.16348125 10.10.181.16:0/4010683472 5 ==== client_request(client.16348125:7933 lookup #0x10000003062/settings 2019-02-18 20:38:04.068523 RETRY=28 caller_uid=33, caller_gid=33{}) v2 ==== 130+0+0 (3754419499 0 0) 0x55b392bd9040 con 0x55b3960d2300
-167> 2019-02-18 21:26:15.949 7ff429169700 3 mds.0.server not active yet, waiting
-166> 2019-02-18 21:26:15.949 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/4010683472 conn(0x55b3960d2300 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=0). rx client.16348125 seq 6 0x55b392bd8340 client_request(client.16348125:7934 lookup #0x10000003062/settings 2019-02-18 20:38:04.068523 RETRY=28 caller_uid=33, caller_gid=33{}) v2
-165> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.16348125 10.10.181.16:0/4010683472 6 ==== client_request(client.16348125:7934 lookup #0x10000003062/settings 2019-02-18 20:38:04.068523 RETRY=28 caller_uid=33, caller_gid=33{}) v2 ==== 130+0+0 (3754419499 0 0) 0x55b392bd8340 con 0x55b3960d2300
-164> 2019-02-18 21:26:15.949 7ff429169700 3 mds.0.server not active yet, waiting
-163> 2019-02-18 21:26:15.949 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/4010683472 conn(0x55b3960d2300 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=0). rx client.16348125 seq 7 0x55b39108d400 client_request(client.16348125:7935 lookup #0x10000003062/settings 2019-02-18 20:38:04.068523 RETRY=28 caller_uid=33, caller_gid=33{}) v2
-162> 2019-02-18 21:26:15.949 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/4010683472 conn(0x55b3960d2300 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=0). rx client.16348125 seq 8 0x55b39108cd80 client_request(client.16348125:7936 lookup #0x10000003062/settings 2019-02-18 20:38:04.072524 RETRY=28 caller_uid=33, caller_gid=33{}) v2
-161> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.16348125 10.10.181.16:0/4010683472 7 ==== client_request(client.16348125:7935 lookup #0x10000003062/settings 2019-02-18 20:38:04.068523 RETRY=28 caller_uid=33, caller_gid=33{}) v2 ==== 130+0+0 (3754419499 0 0) 0x55b39108d400 con 0x55b3960d2300
-160> 2019-02-18 21:26:15.949 7ff429169700 3 mds.0.server not active yet, waiting
-159> 2019-02-18 21:26:15.949 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/4010683472 conn(0x55b3960d2300 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=0). rx client.16348125 seq 9 0x55b39108c3c0 client_request(client.16348125:7937 lookup #0x10000003062/settings 2019-02-18 20:38:04.076524 RETRY=28 caller_uid=33, caller_gid=33{}) v2
-158> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.16348125 10.10.181.16:0/4010683472 8 ==== client_request(client.16348125:7936 lookup #0x10000003062/settings 2019-02-18 20:38:04.072524 RETRY=28 caller_uid=33, caller_gid=33{}) v2 ==== 130+0+0 (1045790300 0 0) 0x55b39108cd80 con 0x55b3960d2300
-157> 2019-02-18 21:26:15.949 7ff429169700 3 mds.0.server not active yet, waiting
-156> 2019-02-18 21:26:15.949 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/4010683472 conn(0x55b3960d2300 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=0). rx client.16348125 seq 10 0x55b39108b040 client_request(client.16348125:7938 lookup #0x10000003062/settings 2019-02-18 20:38:04.080524 RETRY=28 caller_uid=33, caller_gid=33{}) v2
-155> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.16348125 10.10.181.16:0/4010683472 9 ==== client_request(client.16348125:7937 lookup #0x10000003062/settings 2019-02-18 20:38:04.076524 RETRY=28 caller_uid=33, caller_gid=33{}) v2 ==== 130+0+0 (1483220360 0 0) 0x55b39108c3c0 con 0x55b3960d2300
-154> 2019-02-18 21:26:15.949 7ff429169700 3 mds.0.server not active yet, waiting
-153> 2019-02-18 21:26:15.949 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/4010683472 conn(0x55b3960d2300 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=0). rx client.16348125 seq 11 0x55b39108bd40 client_request(client.16348125:7939 lookup #0x10000003062/data_files 2019-02-18 20:38:24.744873 RETRY=26 caller_uid=0, caller_gid=0{}) v2
-152> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.16348125 10.10.181.16:0/4010683472 10 ==== client_request(client.16348125:7938 lookup #0x10000003062/settings 2019-02-18 20:38:04.080524 RETRY=28 caller_uid=33, caller_gid=33{}) v2 ==== 130+0+0 (826656809 0 0) 0x55b39108b040 con 0x55b3960d2300
-151> 2019-02-18 21:26:15.949 7ff429169700 3 mds.0.server not active yet, waiting
-150> 2019-02-18 21:26:15.949 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/4010683472 conn(0x55b3960d2300 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=0). rx client.16348125 seq 12 0x55b39108d0c0 client_request(client.16348125:7940 getattr pAsLsXsFs #0x10000003062 2019-02-18 20:41:05.311586 RETRY=20 caller_uid=0, caller_gid=0{}) v2
-149> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.16348125 10.10.181.16:0/4010683472 11 ==== client_request(client.16348125:7939 lookup #0x10000003062/data_files 2019-02-18 20:38:24.744873 RETRY=26 caller_uid=0, caller_gid=0{}) v2 ==== 132+0+0 (2731758321 0 0) 0x55b39108bd40 con 0x55b3960d2300
-148> 2019-02-18 21:26:15.949 7ff429169700 3 mds.0.server not active yet, waiting
-147> 2019-02-18 21:26:15.949 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/4010683472 conn(0x55b3960d2300 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=0). rx client.16348125 seq 13 0x55b390db9840 client_reconnect(1 caps) v3
-146> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.16348125 10.10.181.16:0/4010683472 12 ==== client_request(client.16348125:7940 getattr pAsLsXsFs #0x10000003062 2019-02-18 20:41:05.311586 RETRY=20 caller_uid=0, caller_gid=0{}) v2 ==== 122+0+0 (2849872508 0 0) 0x55b39108d0c0 con 0x55b3960d2300
-145> 2019-02-18 21:26:15.949 7ff429169700 3 mds.0.server not active yet, waiting
-144> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.16348125 10.10.181.16:0/4010683472 13 ==== client_reconnect(1 caps) v3 ==== 0+0+98 (0 0 729759324) 0x55b390db9840 con 0x55b3960d2300
-143> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.16:0/4010683472 -- client_session(open) v3 -- 0x55b3932e0b40 con 0
-142> 2019-02-18 21:26:15.949 7ff429169700 0 log_channel(cluster) log [DBG] : reconnect by client.16348125 10.10.181.16:0/4010683472 after 0.002474
-141> 2019-02-18 21:26:15.949 7ff429169700 1 mds.0.307 reconnect_done
-140> 2019-02-18 21:26:15.949 7ff429169700 3 mds.0.307 request_state up:rejoin
-139> 2019-02-18 21:26:15.949 7ff429169700 5 mds.beacon.sg1vosrv12 set_want_state: up:reconnect -> up:rejoin
-138> 2019-02-18 21:26:15.949 7ff429169700 5 mds.beacon.sg1vosrv12 Sending beacon up:rejoin seq 4
-137> 2019-02-18 21:26:15.949 7ff429169700 10 monclient: _send_mon_message to mon.12 at 10.10.0.17:6789/0
-136> 2019-02-18 21:26:15.949 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6789/0 -- mdsbeacon(18579226/sg1vosrv12 up:rejoin seq 4 v308) v7 -- 0x55b390fc9880 con 0
-135> 2019-02-18 21:26:16.645 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.181.16:0/3015216276 conn(0x55b396102e00 :6800 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=42 cs=1 l=0). rx client.18110760 seq 2 0x55b3932e0000 client_session(request_renewcaps seq 61967)
-134> 2019-02-18 21:26:16.645 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== client.18110760 10.10.181.16:0/3015216276 2 ==== client_session(request_renewcaps seq 61967) ==== 28+0+0 (1963984816 0 0) 0x55b3932e0000 con 0x55b396102e00
-133> 2019-02-18 21:26:16.645 7ff429169700 3 mds.0.server handle_client_session client_session(request_renewcaps seq 61967) from client.18110760
-132> 2019-02-18 21:26:16.645 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.16:0/3015216276 -- client_session(renewcaps seq 61967) v3 -- 0x55b390db9840 con 0
-131> 2019-02-18 21:26:16.961 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 16 0x55b3910e5b80 mdsmap(e 309) v1
-130> 2019-02-18 21:26:16.961 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 16 ==== mdsmap(e 309) v1 ==== 657+0+0 (1349383830 0 0) 0x55b3910e5b80 con 0x55b39106b500
-129> 2019-02-18 21:26:16.961 7ff429169700 1 mds.sg1vosrv12 Updating MDS map to version 309 from mon.1
-128> 2019-02-18 21:26:16.961 7ff429169700 1 mds.0.307 handle_mds_map i am now mds.0.307
-127> 2019-02-18 21:26:16.961 7ff429169700 1 mds.0.307 handle_mds_map state change up:reconnect --> up:rejoin
-126> 2019-02-18 21:26:16.961 7ff429169700 1 mds.0.307 rejoin_start
-125> 2019-02-18 21:26:16.961 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 17 0x55b390fc9180 mdsbeacon(18579226/sg1vosrv12 up:rejoin seq 4 v309) v7
-124> 2019-02-18 21:26:16.961 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 17 ==== mdsbeacon(18579226/sg1vosrv12 up:rejoin seq 4 v309) v7 ==== 135+0+0 (1249563368 0 0) 0x55b390fc9180 con 0x55b39106b500
-123> 2019-02-18 21:26:16.961 7ff42b16d700 5 mds.beacon.sg1vosrv12 received beacon reply up:rejoin seq 4 rtt 1.01201
-122> 2019-02-18 21:26:16.965 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6817/3799922 -- osd_op(unknown.0.307:60 4.1f 4:ff5b34d6:::1.00000000:head [omap-get-header,omap-get-vals,getxattr parent] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b392bd9a00 con 0
-121> 2019-02-18 21:26:16.965 7ff429169700 1 mds.0.307 rejoin_joint_start
-120> 2019-02-18 21:26:16.965 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=242 cs=1 l=1). rx osd.18 seq 8 0x55b392bd9a00 osd_op_reply(60 1.00000000 [omap-get-header,omap-get-vals,getxattr] v0'0 uv1 ondisk = 0) v8
-119> 2019-02-18 21:26:16.965 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.18 10.10.0.17:6817/3799922 8 ==== osd_op_reply(60 1.00000000 [omap-get-header,omap-get-vals,getxattr] v0'0 uv1 ondisk = 0) v8 ==== 238+0+279 (1510899485 0 3031284639) 0x55b392bd9a00 con 0x55b3910fd800
-118> 2019-02-18 21:26:16.973 7ff421772700 5 mds.0.log _submit_thread 159639406~564 : ESessions 10 opens cmapv 19130
-117> 2019-02-18 21:26:16.973 7ff421772700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6817/3799922 -- osd_op(unknown.0.307:61 4.1f 4:fc76fa7d:::200.00000026:head [write 255854~584] snapc 0=[] ondisk+write+known_if_redirected+full_force e87591) v8 -- 0x55b392bda080 con 0
-116> 2019-02-18 21:26:16.973 7ff421772700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6810/3799921 -- osd_op(unknown.0.307:62 4.14 4:292cf221:::200.00000000:head [writefull 0~90] snapc 0=[] ondisk+write+known_if_redirected+full_force e87591) v8 -- 0x55b392bda3c0 con 0
-115> 2019-02-18 21:26:16.981 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6810/3799921 conn(0x55b3910fca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=248 cs=1 l=1). rx osd.19 seq 12 0x55b392bda3c0 osd_op_reply(62 200.00000000 [writefull 0~90] v87591'1554 uv1554 ondisk = 0) v8
-114> 2019-02-18 21:26:16.981 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.19 10.10.0.17:6810/3799921 12 ==== osd_op_reply(62 200.00000000 [writefull 0~90] v87591'1554 uv1554 ondisk = 0) v8 ==== 156+0+0 (3207574302 0 0) 0x55b392bda3c0 con 0x55b3910fca00
-113> 2019-02-18 21:26:16.985 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=242 cs=1 l=1). rx osd.18 seq 9 0x55b392bda080 osd_op_reply(61 200.00000026 [write 255854~584] v87591'611 uv611 ondisk = 0) v8
-112> 2019-02-18 21:26:16.985 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.18 10.10.0.17:6817/3799922 9 ==== osd_op_reply(61 200.00000026 [write 255854~584] v87591'611 uv611 ondisk = 0) v8 ==== 156+0+0 (162329203 0 0) 0x55b392bda080 con 0x55b3910fd800
-111> 2019-02-18 21:26:16.997 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.18:0/1459513868 -- client_snap(update split=0x3 tracelen=48) v1 -- 0x55b3910e6800 con 0
-110> 2019-02-18 21:26:16.997 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.16:0/4010683472 -- client_snap(update split=0x3 tracelen=48) v1 -- 0x55b3910e6a80 con 0
-109> 2019-02-18 21:26:16.997 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.32.124:0/3176739197 -- client_snap(update split=0x3 tracelen=48) v1 -- 0x55b3910e6d00 con 0
-108> 2019-02-18 21:26:16.997 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.15:0/536186448 -- client_snap(update split=0x3 tracelen=48) v1 -- 0x55b3910e6f80 con 0
-107> 2019-02-18 21:26:16.997 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.16:0/2022917557 -- client_snap(update split=0x3 tracelen=48) v1 -- 0x55b3910e7200 con 0
-106> 2019-02-18 21:26:16.997 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.16:0/742284117 -- client_snap(update split=0x3 tracelen=48) v1 -- 0x55b3910e7480 con 0
-105> 2019-02-18 21:26:16.997 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.15:0/72759821 -- client_snap(update split=0x3 tracelen=48) v1 -- 0x55b3910e7700 con 0
-104> 2019-02-18 21:26:16.997 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.17:0/3643175079 -- client_snap(update split=0x3 tracelen=48) v1 -- 0x55b3910e7980 con 0
-103> 2019-02-18 21:26:16.997 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.17:0/875193457 -- client_snap(update split=0x3 tracelen=48) v1 -- 0x55b3910e7c00 con 0
-102> 2019-02-18 21:26:16.997 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.181.16:0/3015216276 -- client_snap(update split=0x3 tracelen=48) v1 -- 0x55b3932fc000 con 0
-101> 2019-02-18 21:26:16.997 7ff422774700 1 mds.0.307 rejoin_done
-100> 2019-02-18 21:26:17.001 7ff422774700 3 mds.0.307 request_state up:active
-99> 2019-02-18 21:26:17.001 7ff422774700 5 mds.beacon.sg1vosrv12 set_want_state: up:rejoin -> up:active
-98> 2019-02-18 21:26:17.001 7ff422774700 5 mds.beacon.sg1vosrv12 Sending beacon up:active seq 5
-97> 2019-02-18 21:26:17.001 7ff422774700 10 monclient: _send_mon_message to mon.12 at 10.10.0.17:6789/0
-96> 2019-02-18 21:26:17.001 7ff422774700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6789/0 -- mdsbeacon(18579226/sg1vosrv12 up:active seq 5 v309) v7 -- 0x55b390fc9f80 con 0
-95> 2019-02-18 21:26:17.989 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 18 0x55b3910e6580 mdsmap(e 310) v1
-94> 2019-02-18 21:26:17.989 7ff429169700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 18 ==== mdsmap(e 310) v1 ==== 657+0+0 (1086674862 0 0) 0x55b3910e6580 con 0x55b39106b500
-93> 2019-02-18 21:26:17.989 7ff429169700 1 mds.sg1vosrv12 Updating MDS map to version 310 from mon.1
-92> 2019-02-18 21:26:17.989 7ff429169700 1 mds.0.307 handle_mds_map i am now mds.0.307
-91> 2019-02-18 21:26:17.989 7ff429169700 1 mds.0.307 handle_mds_map state change up:rejoin --> up:active
-90> 2019-02-18 21:26:17.989 7ff429169700 1 mds.0.307 recovery_done -- successful recovery!
-89> 2019-02-18 21:26:17.989 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6817/3799922 -- osd_op(unknown.0.307:63 114.14 114:293887a6:gitlab-runner::100000056b7.00000000:head [trimtrunc 2@0] snapc 1=[] ondisk+write+known_if_redirected+full_force e87591) v8 -- 0x55b392bdb740 con 0
-88> 2019-02-18 21:26:17.989 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.18:6801/2707522 -- osd_op(unknown.0.307:64 4.13 4:cd5a64a3:::100.00000000:head [omap-get-header,omap-get-vals,getxattr parent] snapc 0=[] ondisk+read+known_if_redirected+full_force e87591) v8 -- 0x55b392bdba80 con 0
-87> 2019-02-18 21:26:17.989 7ff429169700 1 mds.0.307 active_start
-86> 2019-02-18 21:26:17.989 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6789/0 conn(0x55b39106b500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2110894 cs=1 l=1). rx mon.1 seq 19 0x55b390fc9f80 mdsbeacon(18579226/sg1vosrv12 up:active seq 5 v310) v7
-85> 2019-02-18 21:26:17.989 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== mon.1 10.10.0.17:6789/0 19 ==== mdsbeacon(18579226/sg1vosrv12 up:active seq 5 v310) v7 ==== 135+0+0 (2117385834 0 0) 0x55b390fc9f80 con 0x55b39106b500
-84> 2019-02-18 21:26:17.989 7ff42b16d700 5 mds.beacon.sg1vosrv12 received beacon reply up:active seq 5 rtt 0.988008
-83> 2019-02-18 21:26:17.989 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=242 cs=1 l=1). rx osd.18 seq 10 0x55b392bdb740 osd_op_reply(63 100000056b7.00000000 [trimtrunc 2@0] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-82> 2019-02-18 21:26:17.989 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.18 10.10.0.17:6817/3799922 10 ==== osd_op_reply(63 100000056b7.00000000 [trimtrunc 2@0] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (612139826 0 0) 0x55b392bdb740 con 0x55b3910fd800
-81> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6810/3799921 -- osd_op(unknown.0.307:65 114.17 114:ea9f4152:gitlab-runner::100000056a7.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0c340 con 0
-80> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6817/3799922 -- osd_op(unknown.0.307:66 114.1c 114:3aecad11:gitlab-runner::10000005699.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0c680 con 0
-79> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6802/3799271 -- osd_op(unknown.0.307:67 114.24 114:2620762d:gitlab-runner::10000005698.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0c9c0 con 0
-78> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6821/3799442 -- osd_op(unknown.0.307:68 114.2f 114:f5c02295:gitlab-runner::10000005697.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0cd00 con 0
-77> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6810/3799921 -- osd_op(unknown.0.307:69 114.1a 114:58a0e23b:gitlab-runner::10000005694.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0d040 con 0
-76> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6817/3799922 -- osd_op(unknown.0.307:70 114.e 114:721de89b:gitlab-runner::10000005690.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0d380 con 0
-75> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6817/3799922 -- osd_op(unknown.0.307:71 114.6 114:61710527:gitlab-runner::1000000568f.00000001:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0d6c0 con 0
-74> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6817/3799922 -- osd_op(unknown.0.307:72 114.6 114:62eea092:gitlab-runner::1000000568e.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0da00 con 0
-73> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6810/3799921 -- osd_op(unknown.0.307:73 114.29 114:95e606f1:gitlab-runner::1000000568c.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0dd40 con 0
-72> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6817/3799922 -- osd_op(unknown.0.307:74 114.0 114:01e99402:gitlab-runner::10000005689.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0e080 con 0
-71> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6810/3799921 -- osd_op(unknown.0.307:75 114.1 114:83796fac:gitlab-runner::10000005687.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0e3c0 con 0
-70> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6802/3799271 -- osd_op(unknown.0.307:76 114.20 114:068650c4:gitlab-runner::10000005674.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0e700 con 0
-69> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6826/3799458 -- osd_op(unknown.0.307:77 114.35 114:af710ba0:gitlab-runner::10000005673.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0ea40 con 0
-68> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6802/3799271 -- osd_op(unknown.0.307:78 114.8 114:10feb917:gitlab-runner::10000005670.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0ed80 con 0
-67> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6817/3799922 -- osd_op(unknown.0.307:79 114.1d 114:ba17f1b5:gitlab-runner::1000000566e.000067ff:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0c000 con 0
-66> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6826/3799458 -- osd_op(unknown.0.307:80 114.2b 114:d74ef976:gitlab-runner::10000005660.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0c340 con 0
-65> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6826/3799458 -- osd_op(unknown.0.307:81 114.2b 114:d6c3483d:gitlab-runner::1000000567e.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0d040 con 0
-64> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6817/3799922 -- osd_op(unknown.0.307:82 114.0 114:03d4b8f4:gitlab-runner::100000056a8.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0dd40 con 0
-63> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6826/3799458 -- osd_op(unknown.0.307:83 114.3b 114:dcabfc01:gitlab-runner::100000056a4.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b392bda3c0 con 0
-62> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6821/3799442 -- osd_op(unknown.0.307:84 114.2 114:403f4892:gitlab-runner::100000056a5.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b392bdba80 con 0
-61> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6817/3799922 -- osd_op(unknown.0.307:85 114.18 114:18823eaa:gitlab-runner::100000056b8.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b39108da80 con 0
-60> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6802/3799271 -- osd_op(unknown.0.307:86 114.3a 114:5e028501:gitlab-runner::10000005691.00000000:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0e3c0 con 0
-59> 2019-02-18 21:26:17.993 7ff429169700 1 -- 10.10.32.124:6800/3814621597 --> 10.10.0.17:6826/3799458 -- osd_op(unknown.0.307:87 114.3b 114:ddf3e7e7:gitlab-runner::1000000566f.00000400:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e87591) v8 -- 0x55b394f0f0c0 con 0
-58> 2019-02-18 21:26:17.993 7ff429169700 4 mds.0.server handle_client_request client_request(client.17592384:659 lookup #0x10000000009/lock_yBgMBwiR 2019-02-18 20:37:27.949525 RETRY=30 caller_uid=33, caller_gid=33{}) v2
-57> 2019-02-18 21:26:17.993 7ff429169700 5 mds.0.server waiting for root
-56> 2019-02-18 21:26:17.993 7ff429169700 4 mds.0.server handle_client_request client_request(client.17592384:660 lookup #0x10000000009/lock_yBgMBwiR 2019-02-18 20:37:43.617901 RETRY=29 caller_uid=0, caller_gid=0{}) v2
-55> 2019-02-18 21:26:17.993 7ff429169700 5 mds.0.server waiting for root
-54> 2019-02-18 21:26:17.993 7ff429169700 4 mds.0.server handle_client_request client_request(client.17492882:26 lookup #0x10000000009/lock_yBgMBwiR 2019-02-18 20:37:28.578641 RETRY=30 caller_uid=33, caller_gid=33{}) v2
-53> 2019-02-18 21:26:17.993 7ff429169700 5 mds.0.server waiting for root
-52> 2019-02-18 21:26:17.993 7ff429169700 4 mds.0.server handle_client_request client_request(client.17492882:27 lookup #0x10000000009/lock_yBgMBwiR 2019-02-18 20:37:44.251014 RETRY=28 caller_uid=0, caller_gid=0{}) v2
-51> 2019-02-18 21:26:17.993 7ff429169700 5 mds.0.server waiting for root
-50> 2019-02-18 21:26:17.993 7ff429169700 4 mds.0.server handle_client_request client_request(client.16348125:7929 lookup #0x10000003062/settings 2019-02-18 20:37:27.747910 RETRY=30 caller_uid=33, caller_gid=33{}) v2
-49> 2019-02-18 21:26:17.993 7ff429169700 5 mds.0.server waiting for root
-48> 2019-02-18 21:26:17.993 7ff429169700 4 mds.0.server handle_client_request client_request(client.16348125:7930 lookup #0x10000003062/settings 2019-02-18 20:38:04.068523 RETRY=28 caller_uid=33, caller_gid=33{}) v2
-47> 2019-02-18 21:26:17.993 7ff429169700 5 mds.0.server waiting for root
-46> 2019-02-18 21:26:17.993 7ff429169700 4 mds.0.server handle_client_request client_request(client.16348125:7931 lookup #0x10000003062/settings 2019-02-18 20:38:04.068523 RETRY=28 caller_uid=33, caller_gid=33{}) v2
-45> 2019-02-18 21:26:17.993 7ff429169700 5 mds.0.server waiting for root
-44> 2019-02-18 21:26:17.993 7ff429169700 4 mds.0.server handle_client_request client_request(client.16348125:7932 lookup #0x10000003062/settings 2019-02-18 20:38:04.068523 RETRY=28 caller_uid=33, caller_gid=33{}) v2
-43> 2019-02-18 21:26:17.993 7ff429169700 5 mds.0.server waiting for root
-42> 2019-02-18 21:26:17.993 7ff429169700 4 mds.0.server handle_client_request client_request(client.16348125:7933 lookup #0x10000003062/settings 2019-02-18 20:38:04.068523 RETRY=28 caller_uid=33, caller_gid=33{}) v2
-41> 2019-02-18 21:26:17.993 7ff429169700 5 mds.0.server waiting for root
-40> 2019-02-18 21:26:17.993 7ff429169700 4 mds.0.server handle_client_request client_request(client.16348125:7934 lookup #0x10000003062/settings 2019-02-18 20:38:04.068523 RETRY=28 caller_uid=33, caller_gid=33{}) v2
-39> 2019-02-18 21:26:17.993 7ff429169700 5 mds.0.server waiting for root
-38> 2019-02-18 21:26:17.993 7ff429169700 4 mds.0.server handle_client_request client_request(client.16348125:7935 lookup #0x10000003062/settings 2019-02-18 20:38:04.068523 RETRY=28 caller_uid=33, caller_gid=33{}) v2
-37> 2019-02-18 21:26:17.993 7ff429169700 5 mds.0.server waiting for root
-36> 2019-02-18 21:26:17.993 7ff429169700 4 mds.0.server handle_client_request client_request(client.16348125:7936 lookup #0x10000003062/settings 2019-02-18 20:38:04.072524 RETRY=28 caller_uid=33, caller_gid=33{}) v2
-35> 2019-02-18 21:26:17.993 7ff429169700 5 mds.0.server waiting for root
-34> 2019-02-18 21:26:17.993 7ff429169700 4 mds.0.server handle_client_request client_request(client.16348125:7937 lookup #0x10000003062/settings 2019-02-18 20:38:04.076524 RETRY=28 caller_uid=33, caller_gid=33{}) v2
-33> 2019-02-18 21:26:17.993 7ff429169700 5 mds.0.server waiting for root
-32> 2019-02-18 21:26:17.993 7ff429169700 4 mds.0.server handle_client_request client_request(client.16348125:7938 lookup #0x10000003062/settings 2019-02-18 20:38:04.080524 RETRY=28 caller_uid=33, caller_gid=33{}) v2
-31> 2019-02-18 21:26:17.993 7ff429169700 5 mds.0.server waiting for root
-30> 2019-02-18 21:26:17.993 7ff429169700 4 mds.0.server handle_client_request client_request(client.16348125:7939 lookup #0x10000003062/data_files 2019-02-18 20:38:24.744873 RETRY=26 caller_uid=0, caller_gid=0{}) v2
-29> 2019-02-18 21:26:17.993 7ff429169700 5 mds.0.server waiting for root
-28> 2019-02-18 21:26:17.993 7ff429169700 4 mds.0.server handle_client_request client_request(client.16348125:7940 getattr pAsLsXsFs #0x10000003062 2019-02-18 20:41:05.311586 RETRY=20 caller_uid=0, caller_gid=0{}) v2
-27> 2019-02-18 21:26:17.993 7ff429169700 5 mds.0.server waiting for root
-26> 2019-02-18 21:26:17.993 7ff429169700 1 mds.0.307 cluster recovered.
-25> 2019-02-18 21:26:17.993 7ff429169700 4 mds.0.307 set_osd_epoch_barrier: epoch=87591
-24> 2019-02-18 21:26:17.993 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6810/3799921 conn(0x55b3910fca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=248 cs=1 l=1). rx osd.19 seq 13 0x55b394a92000 osd_op_reply(65 100000056a7.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-23> 2019-02-18 21:26:17.993 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.19 10.10.0.17:6810/3799921 13 ==== osd_op_reply(65 100000056a7.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (2400418593 0 0) 0x55b394a92000 con 0x55b3910fca00
-22> 2019-02-18 21:26:17.993 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6810/3799921 conn(0x55b3910fca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=248 cs=1 l=1). rx osd.19 seq 14 0x55b394a92000 osd_op_reply(69 10000005694.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-21> 2019-02-18 21:26:17.993 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.19 10.10.0.17:6810/3799921 14 ==== osd_op_reply(69 10000005694.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (3674099109 0 0) 0x55b394a92000 con 0x55b3910fca00
-20> 2019-02-18 21:26:17.993 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6810/3799921 conn(0x55b3910fca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=248 cs=1 l=1). rx osd.19 seq 15 0x55b394a92000 osd_op_reply(73 1000000568c.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-19> 2019-02-18 21:26:17.993 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.19 10.10.0.17:6810/3799921 15 ==== osd_op_reply(73 1000000568c.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (3569968655 0 0) 0x55b394a92000 con 0x55b3910fca00
-18> 2019-02-18 21:26:17.993 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6810/3799921 conn(0x55b3910fca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=248 cs=1 l=1). rx osd.19 seq 16 0x55b394a92000 osd_op_reply(75 10000005687.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-17> 2019-02-18 21:26:17.993 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.19 10.10.0.17:6810/3799921 16 ==== osd_op_reply(75 10000005687.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (1026618483 0 0) 0x55b394a92000 con 0x55b3910fca00
-16> 2019-02-18 21:26:17.993 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=242 cs=1 l=1). rx osd.18 seq 11 0x55b39108da80 osd_op_reply(66 10000005699.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-15> 2019-02-18 21:26:17.993 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.18 10.10.0.17:6817/3799922 11 ==== osd_op_reply(66 10000005699.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (931822677 0 0) 0x55b39108da80 con 0x55b3910fd800
-14> 2019-02-18 21:26:17.993 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=242 cs=1 l=1). rx osd.18 seq 12 0x55b39108da80 osd_op_reply(70 10000005690.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-13> 2019-02-18 21:26:17.993 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.18 10.10.0.17:6817/3799922 12 ==== osd_op_reply(70 10000005690.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (382550529 0 0) 0x55b39108da80 con 0x55b3910fd800
-12> 2019-02-18 21:26:17.993 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=242 cs=1 l=1). rx osd.18 seq 13 0x55b39108da80 osd_op_reply(71 1000000568f.00000001 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-11> 2019-02-18 21:26:17.993 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.18 10.10.0.17:6817/3799922 13 ==== osd_op_reply(71 1000000568f.00000001 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (3338416371 0 0) 0x55b39108da80 con 0x55b3910fd800
-10> 2019-02-18 21:26:17.993 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=242 cs=1 l=1). rx osd.18 seq 14 0x55b39108da80 osd_op_reply(72 1000000568e.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-9> 2019-02-18 21:26:17.993 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.18 10.10.0.17:6817/3799922 14 ==== osd_op_reply(72 1000000568e.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (246325923 0 0) 0x55b39108da80 con 0x55b3910fd800
-8> 2019-02-18 21:26:17.993 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=242 cs=1 l=1). rx osd.18 seq 15 0x55b39108da80 osd_op_reply(74 10000005689.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-7> 2019-02-18 21:26:17.993 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.18 10.10.0.17:6817/3799922 15 ==== osd_op_reply(74 10000005689.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (2743847341 0 0) 0x55b39108da80 con 0x55b3910fd800
-6> 2019-02-18 21:26:17.993 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=242 cs=1 l=1). rx osd.18 seq 16 0x55b39108da80 osd_op_reply(79 1000000566e.000067ff [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-5> 2019-02-18 21:26:17.993 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.18 10.10.0.17:6817/3799922 16 ==== osd_op_reply(79 1000000566e.000067ff [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (527551856 0 0) 0x55b39108da80 con 0x55b3910fd800
-4> 2019-02-18 21:26:17.993 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=242 cs=1 l=1). rx osd.18 seq 17 0x55b39108da80 osd_op_reply(82 100000056a8.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-3> 2019-02-18 21:26:17.993 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.18 10.10.0.17:6817/3799922 17 ==== osd_op_reply(82 100000056a8.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (2169333281 0 0) 0x55b39108da80 con 0x55b3910fd800
-2> 2019-02-18 21:26:17.993 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6817/3799922 conn(0x55b3910fd800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=242 cs=1 l=1). rx osd.18 seq 18 0x55b39108da80 osd_op_reply(85 100000056b8.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-1> 2019-02-18 21:26:17.993 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.18 10.10.0.17:6817/3799922 18 ==== osd_op_reply(85 100000056b8.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (1497311681 0 0) 0x55b39108da80 con 0x55b3910fd800
0> 2019-02-18 21:26:17.993 7ff422774700 -1 /home/jerome.poulin/GIT/ceph/src/mds/MDCache.cc: In function 'virtual void C_IO_MDC_TruncateFinish::finish(int)' thread 7ff422774700 time 2019-02-18 21:26:17.997688
/home/jerome.poulin/GIT/ceph/src/mds/MDCache.cc: 6476: FAILED assert(r == 0 || r == -2)

ceph version 13.2.4 (b10be4d44915a4d78a8e06aa31919e74927b142e) mimic (stable)
1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x102) [0x7ff431379642]
2: (()+0x26d807) [0x7ff431379807]
3: (C_MDC_FragmentFrozen::finish(int)+0) [0x55b38e305700]
4: (MDSIOContextBase::complete(int)+0x119) [0x55b38e4254e9]
5: (Finisher::finisher_thread_entry()+0x12e) [0x7ff431377bde]
6: (()+0x76db) [0x7ff430c846db]
7: (clone()+0x3f) [0x7ff42fe6a88f]
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
1/ 5 osd
0/ 5 optracker
0/ 5 objclass
1/ 3 filestore
1/ 3 journal
0/ 5 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
1/ 5 bluestore
1/ 5 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
--- end dump of recent events ---
*** Caught signal (Aborted) **
in thread 7ff422774700 thread_name:fn_anonymous
ceph version 13.2.4 (b10be4d44915a4d78a8e06aa31919e74927b142e) mimic (stable)
1: (()+0x405ff0) [0x55b38e4a4ff0]
2: (()+0x12890) [0x7ff430c8f890]
3: (gsignal()+0xc7) [0x7ff42fd87e97]
4: (abort()+0x141) [0x7ff42fd89801]
5: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x250) [0x7ff431379790]
6: (()+0x26d807) [0x7ff431379807]
7: (C_MDC_FragmentFrozen::finish(int)+0) [0x55b38e305700]
8: (MDSIOContextBase::complete(int)+0x119) [0x55b38e4254e9]
9: (Finisher::finisher_thread_entry()+0x12e) [0x7ff431377bde]
10: (()+0x76db) [0x7ff430c846db]
11: (clone()+0x3f) [0x7ff42fe6a88f]
2019-02-18 21:26:18.013 7ff422774700 -1 *** Caught signal (Aborted) **
in thread 7ff422774700 thread_name:fn_anonymous

ceph version 13.2.4 (b10be4d44915a4d78a8e06aa31919e74927b142e) mimic (stable)
1: (()+0x405ff0) [0x55b38e4a4ff0]
2: (()+0x12890) [0x7ff430c8f890]
3: (gsignal()+0xc7) [0x7ff42fd87e97]
4: (abort()+0x141) [0x7ff42fd89801]
5: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x250) [0x7ff431379790]
6: (()+0x26d807) [0x7ff431379807]
7: (C_MDC_FragmentFrozen::finish(int)+0) [0x55b38e305700]
8: (MDSIOContextBase::complete(int)+0x119) [0x55b38e4254e9]
9: (Finisher::finisher_thread_entry()+0x12e) [0x7ff431377bde]
10: (()+0x76db) [0x7ff430c846db]
11: (clone()+0x3f) [0x7ff42fe6a88f]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- begin dump of recent events ---
-27> 2019-02-18 21:26:17.993 7ff42b16d700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6821/3799442 conn(0x55b3960f2300 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-26> 2019-02-18 21:26:17.993 7ff42b96e700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6802/3799271 conn(0x55b39106ca00 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-25> 2019-02-18 21:26:17.993 7ff42c16f700 2 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6826/3799458 conn(0x55b3960cf800 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-24> 2019-02-18 21:26:17.993 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.18:6801/2707522 conn(0x55b39106d800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=66 cs=1 l=1). rx osd.4 seq 9 0x55b394f0f0c0 osd_op_reply(64 100.00000000 [omap-get-header,omap-get-vals,getxattr] v0'0 uv1 ondisk = 0) v8
-23> 2019-02-18 21:26:17.993 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.4 10.10.0.18:6801/2707522 9 ==== osd_op_reply(64 100.00000000 [omap-get-header,omap-get-vals,getxattr] v0'0 uv1 ondisk = 0) v8 ==== 240+0+5089 (1492872951 0 3728907065) 0x55b394f0f0c0 con 0x55b39106d800
-22> 2019-02-18 21:26:17.997 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6821/3799442 conn(0x55b3960f2300 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=243 cs=1 l=1). rx osd.8 seq 1 0x55b392bdba80 osd_op_reply(68 10000005697.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-21> 2019-02-18 21:26:17.997 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== osd.8 10.10.0.17:6821/3799442 1 ==== osd_op_reply(68 10000005697.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (924941900 0 0) 0x55b392bdba80 con 0x55b3960f2300
-20> 2019-02-18 21:26:17.997 7ff42b16d700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6821/3799442 conn(0x55b3960f2300 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=243 cs=1 l=1). rx osd.8 seq 2 0x55b392bdba80 osd_op_reply(84 100000056a5.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-19> 2019-02-18 21:26:17.997 7ff42b16d700 1 -- 10.10.32.124:6800/3814621597 <== osd.8 10.10.0.17:6821/3799442 2 ==== osd_op_reply(84 100000056a5.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (4255271075 0 0) 0x55b392bdba80 con 0x55b3960f2300
-18> 2019-02-18 21:26:17.997 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6802/3799271 conn(0x55b39106ca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=160 cs=1 l=1). rx osd.6 seq 1 0x55b394f0e3c0 osd_op_reply(67 10000005698.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-17> 2019-02-18 21:26:17.997 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.6 10.10.0.17:6802/3799271 1 ==== osd_op_reply(67 10000005698.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (3280643073 0 0) 0x55b394f0e3c0 con 0x55b39106ca00
-16> 2019-02-18 21:26:17.997 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6802/3799271 conn(0x55b39106ca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=160 cs=1 l=1). rx osd.6 seq 2 0x55b394f0e3c0 osd_op_reply(76 10000005674.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-15> 2019-02-18 21:26:17.997 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.6 10.10.0.17:6802/3799271 2 ==== osd_op_reply(76 10000005674.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (2021027203 0 0) 0x55b394f0e3c0 con 0x55b39106ca00
-14> 2019-02-18 21:26:17.997 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6802/3799271 conn(0x55b39106ca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=160 cs=1 l=1). rx osd.6 seq 3 0x55b394f0e3c0 osd_op_reply(78 10000005670.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-13> 2019-02-18 21:26:17.997 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.6 10.10.0.17:6802/3799271 3 ==== osd_op_reply(78 10000005670.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (3587802430 0 0) 0x55b394f0e3c0 con 0x55b39106ca00
-12> 2019-02-18 21:26:17.997 7ff42b96e700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6802/3799271 conn(0x55b39106ca00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=160 cs=1 l=1). rx osd.6 seq 4 0x55b394f0e3c0 osd_op_reply(86 10000005691.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-11> 2019-02-18 21:26:17.997 7ff42b96e700 1 -- 10.10.32.124:6800/3814621597 <== osd.6 10.10.0.17:6802/3799271 4 ==== osd_op_reply(86 10000005691.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (1435290930 0 0) 0x55b394f0e3c0 con 0x55b39106ca00
-10> 2019-02-18 21:26:17.997 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6826/3799458 conn(0x55b3960cf800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=192 cs=1 l=1). rx osd.7 seq 1 0x55b392bda3c0 osd_op_reply(77 10000005673.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-9> 2019-02-18 21:26:17.997 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.7 10.10.0.17:6826/3799458 1 ==== osd_op_reply(77 10000005673.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (517799618 0 0) 0x55b392bda3c0 con 0x55b3960cf800
-8> 2019-02-18 21:26:17.997 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6826/3799458 conn(0x55b3960cf800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=192 cs=1 l=1). rx osd.7 seq 2 0x55b392bda3c0 osd_op_reply(80 10000005660.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-7> 2019-02-18 21:26:17.997 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.7 10.10.0.17:6826/3799458 2 ==== osd_op_reply(80 10000005660.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (3457787074 0 0) 0x55b392bda3c0 con 0x55b3960cf800
-6> 2019-02-18 21:26:17.997 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6826/3799458 conn(0x55b3960cf800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=192 cs=1 l=1). rx osd.7 seq 3 0x55b392bda3c0 osd_op_reply(81 1000000567e.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-5> 2019-02-18 21:26:17.997 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.7 10.10.0.17:6826/3799458 3 ==== osd_op_reply(81 1000000567e.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (4037020789 0 0) 0x55b392bda3c0 con 0x55b3960cf800
-4> 2019-02-18 21:26:17.997 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6826/3799458 conn(0x55b3960cf800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=192 cs=1 l=1). rx osd.7 seq 4 0x55b392bda3c0 osd_op_reply(83 100000056a4.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-3> 2019-02-18 21:26:17.997 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.7 10.10.0.17:6826/3799458 4 ==== osd_op_reply(83 100000056a4.00000000 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (2939317331 0 0) 0x55b392bda3c0 con 0x55b3960cf800
-2> 2019-02-18 21:26:17.997 7ff42c16f700 5 -- 10.10.32.124:6800/3814621597 >> 10.10.0.17:6826/3799458 conn(0x55b3960cf800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=192 cs=1 l=1). rx osd.7 seq 5 0x55b392bda3c0 osd_op_reply(87 1000000566f.00000400 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8
-1> 2019-02-18 21:26:17.997 7ff42c16f700 1 -- 10.10.32.124:6800/3814621597 <== osd.7 10.10.0.17:6826/3799458 5 ==== osd_op_reply(87 1000000566f.00000400 [stat] v0'0 uv0 ondisk = -1 ((1) Operation not permitted)) v8 ==== 164+0+0 (656623127 0 0) 0x55b392bda3c0 con 0x55b3960cf800
0> 2019-02-18 21:26:18.013 7ff422774700 -1 *** Caught signal (Aborted) **
in thread 7ff422774700 thread_name:fn_anonymous

ceph version 13.2.4 (b10be4d44915a4d78a8e06aa31919e74927b142e) mimic (stable)
1: (()+0x405ff0) [0x55b38e4a4ff0]
2: (()+0x12890) [0x7ff430c8f890]
3: (gsignal()+0xc7) [0x7ff42fd87e97]
4: (abort()+0x141) [0x7ff42fd89801]
5: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x250) [0x7ff431379790]
6: (()+0x26d807) [0x7ff431379807]
7: (C_MDC_FragmentFrozen::finish(int)+0) [0x55b38e305700]
8: (MDSIOContextBase::complete(int)+0x119) [0x55b38e4254e9]
9: (Finisher::finisher_thread_entry()+0x12e) [0x7ff431377bde]
10: (()+0x76db) [0x7ff430c846db]
11: (clone()+0x3f) [0x7ff42fe6a88f]
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
1/ 5 osd
0/ 5 optracker
0/ 5 objclass
1/ 3 filestore
1/ 3 journal
0/ 5 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
1/ 5 bluestore
1/ 5 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
--- end dump of recent events ---
Aborted
(1-1/2)