Bug #13527
Updated by Loïc Dachary over 8 years ago
2015-10-19 16:50:58.903409 7fca00c84940 0 ceph version 9.1.0-227-gc55f8d4 (c55f8d4300019bf2da1fe52edb0c2151cc8e3d2e), process ceph-mon, pid 1993 2015-10-19 16:50:58.915238 7fca00c84940 0 starting mon.ceph2 rank 1 at 192.168.72.42:6789/0 mon_data /var/lib/ceph/mon/ceph-ceph2 fsid f47da131-dc71-4768-844c-e71bf68d4f03 2015-10-19 16:50:58.915440 7fca00c84940 1 mon.ceph2@-1(probing) e0 preinit fsid f47da131-dc71-4768-844c-e71bf68d4f03 2015-10-19 16:50:58.915494 7fca00c84940 1 mon.ceph2@-1(probing) e0 initial_members ceph1,ceph2,ceph3, filtering seed monmap 2015-10-19 16:50:58.915998 7fca00c84940 0 mon.ceph2@-1(probing) e0 my rank is now 0 (was -1) 2015-10-19 16:50:58.916185 7fca00c82700 0 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/1 pipe(0x7fca054dc000 sd=12 :0 s=1 pgs=0 cs=0 l=0 c=0x7fca05321340).fault 2015-10-19 16:50:58.916228 7fca002ac700 0 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/2 pipe(0x7fca054e1000 sd=13 :0 s=1 pgs=0 cs=0 l=0 c=0x7fca053211e0).fault 2015-10-19 16:50:58.916417 7fc9f58ec700 0 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7fca054e6000 sd=15 :0 s=1 pgs=0 cs=0 l=0 c=0x7fca05320f20).fault 2015-10-19 16:50:58.916790 7fc9f59ed700 0 cephx: verify_reply couldn't decrypt with error: error decoding block for decryption 2015-10-19 16:50:58.916795 7fc9f59ed700 0 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7fca054eb000 sd=14 :36353 s=1 pgs=0 cs=0 l=0 c=0x7fca05321080).failed verifying authorize reply 2015-10-19 16:50:58.916810 7fc9f59ed700 0 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7fca054eb000 sd=14 :36353 s=1 pgs=0 cs=0 l=0 c=0x7fca05321080).fault 2015-10-19 16:50:58.917304 7fc9f59ed700 0 cephx: verify_reply couldn't decrypt with error: error decoding block for decryption 2015-10-19 16:50:58.917308 7fc9f59ed700 0 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7fca054eb000 sd=14 :36358 s=1 pgs=0 cs=0 l=0 c=0x7fca05321080).failed verifying authorize reply 2015-10-19 16:50:58.917315 7fc9f4fea700 0 cephx: verify_authorizer could not decrypt ticket info: error: NSS AES final round failed: -8190 2015-10-19 16:50:58.917344 7fc9f4fea700 0 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7fca0550c000 sd=24 :6789 s=0 pgs=0 cs=0 l=0 c=0x7fca053214a0).accept connect_seq 0 vs existing 0 state connecting 2015-10-19 16:59:15.449488 7f5d6b112940 0 ceph version 9.1.0-227-gc55f8d4 (c55f8d4300019bf2da1fe52edb0c2151cc8e3d2e), process ceph-mon, pid 2300 2015-10-19 16:59:15.461874 7f5d6b112940 0 starting mon.ceph2 rank 1 at 192.168.72.42:6789/0 mon_data /var/lib/ceph/mon/ceph-ceph2 fsid f47da131-dc71-4768-844c-e71bf68d4f03 2015-10-19 16:59:15.462043 7f5d6b112940 1 mon.ceph2@-1(probing) e0 preinit fsid f47da131-dc71-4768-844c-e71bf68d4f03 2015-10-19 16:59:15.462084 7f5d6b112940 1 mon.ceph2@-1(probing) e0 initial_members ceph1,ceph2,ceph3, filtering seed monmap 2015-10-19 16:59:15.462446 7f5d6b112940 0 mon.ceph2@-1(probing) e0 my rank is now 0 (was -1) 2015-10-19 16:59:15.462648 7f5d6b110700 0 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/1 pipe(0x7f5d6f860000 sd=12 :0 s=1 pgs=0 cs=0 l=0 c=0x7f5d6f6a5340).fault 2015-10-19 16:59:15.462718 7f5d6a73a700 0 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/2 pipe(0x7f5d6f865000 sd=13 :0 s=1 pgs=0 cs=0 l=0 c=0x7f5d6f6a51e0).fault 2015-10-19 16:59:15.463039 7f5d5fd7a700 0 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f5d6f86a000 sd=23 :0 s=1 pgs=0 cs=0 l=0 c=0x7f5d6f6a4f20).fault 2015-10-19 16:59:15.463483 7f5d5fe7b700 0 cephx: verify_reply couldn't decrypt with error: error decoding block for decryption 2015-10-19 16:59:15.463492 7f5d5fe7b700 0 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7f5d6f86f000 sd=14 :36361 s=1 pgs=0 cs=0 l=0 c=0x7f5d6f6a5080).failed verifying authorize reply 2015-10-19 16:59:15.463523 7f5d5fe7b700 0 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7f5d6f86f000 sd=14 :36361 s=1 pgs=0 cs=0 l=0 c=0x7f5d6f6a5080).fault 2015-10-19 16:59:15.464184 7f5d5f478700 0 cephx: verify_authorizer could not decrypt ticket info: error: NSS AES final round failed: -8190 2015-10-19 16:59:15.464191 7f5d5f478700 0 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7f5d6f890000 sd=24 :6789 s=0 pgs=0 cs=0 l=0 c=0x7f5d6f6a54a0).accept connect_seq 0 vs existing 0 state connecting 2015-10-19 16:59:15.464203 7f5d5fe7b700 0 cephx: verify_reply couldn't decrypt with error: error decoding block for decryption 2015-10-19 16:59:15.464207 7f5d5fe7b700 0 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7f5d6f86f000 sd=14 :36366 s=4 pgs=0 cs=0 l=0 c=0x7f5d6f6a5080).failed verifying authorize reply 2015-10-19 16:59:15.610005 7f066c070940 0 ceph version 9.1.0-227-gc55f8d4 (c55f8d4300019bf2da1fe52edb0c2151cc8e3d2e), process ceph-mon, pid 2329 2015-10-19 16:59:15.620165 7f066c070940 0 starting mon.ceph2 rank 1 at 192.168.72.42:6789/0 mon_data /var/lib/ceph/mon/ceph-ceph2 fsid f47da131-dc71-4768-844c-e71bf68d4f03 2015-10-19 16:59:15.620317 7f066c070940 1 mon.ceph2@-1(probing) e0 preinit fsid f47da131-dc71-4768-844c-e71bf68d4f03 2015-10-19 16:59:15.620360 7f066c070940 1 mon.ceph2@-1(probing) e0 initial_members ceph1,ceph2,ceph3, filtering seed monmap 2015-10-19 16:59:15.620707 7f066c070940 0 mon.ceph2@-1(probing) e0 my rank is now 0 (was -1) 2015-10-19 16:59:15.620899 7f066c06e700 0 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/1 pipe(0x7f066fe52000 sd=12 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97340).fault 2015-10-19 16:59:15.620957 7f066b698700 0 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/2 pipe(0x7f066fe57000 sd=13 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc971e0).fault 2015-10-19 16:59:15.621177 7f0660cd8700 0 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066fe5c000 sd=23 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc96f20).fault 2015-10-19 16:59:15.679720 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd='mon_status' args=[]: dispatch 2015-10-19 16:59:15.679815 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd=mon_status args=[]: finished 2015-10-19 16:59:15.809468 7f0660dd9700 0 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7f066fe61000 sd=14 :36369 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97080).fault 2015-10-19 16:59:16.742414 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd='mon_status' args=[]: dispatch 2015-10-19 16:59:16.742507 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd=mon_status args=[]: finished 2015-10-19 16:59:17.499193 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd='mon_status' args=[]: dispatch 2015-10-19 16:59:17.499254 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd=mon_status args=[]: finished 2015-10-19 16:59:17.616543 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd='mon_status' args=[]: dispatch 2015-10-19 16:59:17.616619 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd=mon_status args=[]: finished 2015-10-19 16:59:17.806207 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd='mon_status' args=[]: dispatch 2015-10-19 16:59:17.806320 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd=mon_status args=[]: finished 2015-10-19 16:59:18.479309 7f06603d6700 0 cephx: verify_authorizer could not decrypt ticket info: error: NSS AES final round failed: -8190 2015-10-19 16:59:18.479320 7f06603d6700 0 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066feb2000 sd=24 :6789 s=0 pgs=0 cs=0 l=0 c=0x7f066fc974a0).accept connect_seq 0 vs existing 0 state connecting 2015-10-19 16:59:18.479948 7f06603d6700 0 cephx: verify_authorizer could not decrypt ticket info: error: NSS AES final round failed: -8190 2015-10-19 16:59:18.479958 7f06603d6700 0 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066feb7000 sd=24 :6789 s=0 pgs=0 cs=0 l=0 c=0x7f066fc97600).accept connect_seq 0 vs existing 0 state connecting 2015-10-19 16:59:18.479986 7f0660cd8700 0 cephx: verify_reply couldn't decrypt with error: error decoding block for decryption 2015-10-19 16:59:18.479992 7f0660cd8700 0 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066fe5c000 sd=23 :53881 s=1 pgs=0 cs=0 l=0 c=0x7f066fc96f20).failed verifying authorize reply 2015-10-19 16:59:18.643689 7f06603d6700 -1 *** Caught signal (Segmentation fault) ** in thread 7f06603d6700 ceph version 9.1.0-227-gc55f8d4 (c55f8d4300019bf2da1fe52edb0c2151cc8e3d2e) 1: (()+0x68d75a) [0x7f066bd2975a] 2: (()+0x10340) [0x7f066a538340] 3: (PK11_DoesMechanism()+0x5f) [0x7f066a2404bf] 4: (()+0x33027) [0x7f066a221027] 5: (()+0x4cf2a) [0x7f066a23af2a] 6: (()+0x4cf7b) [0x7f066a23af7b] 7: (PK11_CreateContextBySymKey()+0x22) [0x7f066a21fe62] 8: (()+0x374407) [0x7f066ba10407] 9: (CryptoAESKeyHandler::decrypt(ceph::buffer::list const&, ceph::buffer::list&, std::string*) const+0x2a) [0x7f066ba111ca] 10: (void decode_decrypt_enc_bl<CephXServiceTicketInfo>(CephContext*, CephXServiceTicketInfo&, CryptoKey, ceph::buffer::list&, std::string&)+0xba) [0x7f066ba0874a] 11: (cephx_verify_authorizer(CephContext*, KeyStore*, ceph::buffer::list::iterator&, CephXServiceTicketInfo&, ceph::buffer::list&)+0x394) [0x7f066ba03a94] 12: (Monitor::ms_verify_authorizer(Connection*, int, int, ceph::buffer::list&, ceph::buffer::list&, bool&, CryptoKey&)+0x409) [0x7f066b8b3179] 13: (SimpleMessenger::verify_authorizer(Connection*, int, int, ceph::buffer::list&, ceph::buffer::list&, bool&, CryptoKey&)+0x7f) [0x7f066bad955f] 14: (Pipe::accept()+0x1e51) [0x7f066bc9f191] 15: (Pipe::reader()+0x19ff) [0x7f066bca3e1f] 16: (Pipe::Reader::entry()+0xd) [0x7f066bcabccd] 17: (()+0x8182) [0x7f066a530182] 18: (clone()+0x6d) [0x7f0668a9d47d] NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this. --- begin dump of recent events --- -337> 2015-10-19 16:59:15.606342 7f066c070940 5 asok(0x7f066fd06000) register_command perfcounters_dump hook 0x7f066fc7a050 -336> 2015-10-19 16:59:15.606364 7f066c070940 5 asok(0x7f066fd06000) register_command 1 hook 0x7f066fc7a050 -335> 2015-10-19 16:59:15.606368 7f066c070940 5 asok(0x7f066fd06000) register_command perf dump hook 0x7f066fc7a050 -334> 2015-10-19 16:59:15.606370 7f066c070940 5 asok(0x7f066fd06000) register_command perfcounters_schema hook 0x7f066fc7a050 -333> 2015-10-19 16:59:15.606374 7f066c070940 5 asok(0x7f066fd06000) register_command 2 hook 0x7f066fc7a050 -332> 2015-10-19 16:59:15.606375 7f066c070940 5 asok(0x7f066fd06000) register_command perf schema hook 0x7f066fc7a050 -331> 2015-10-19 16:59:15.606379 7f066c070940 5 asok(0x7f066fd06000) register_command perf reset hook 0x7f066fc7a050 -330> 2015-10-19 16:59:15.606381 7f066c070940 5 asok(0x7f066fd06000) register_command config show hook 0x7f066fc7a050 -329> 2015-10-19 16:59:15.606385 7f066c070940 5 asok(0x7f066fd06000) register_command config set hook 0x7f066fc7a050 -328> 2015-10-19 16:59:15.606387 7f066c070940 5 asok(0x7f066fd06000) register_command config get hook 0x7f066fc7a050 -327> 2015-10-19 16:59:15.606390 7f066c070940 5 asok(0x7f066fd06000) register_command config diff hook 0x7f066fc7a050 -326> 2015-10-19 16:59:15.606392 7f066c070940 5 asok(0x7f066fd06000) register_command log flush hook 0x7f066fc7a050 -325> 2015-10-19 16:59:15.606396 7f066c070940 5 asok(0x7f066fd06000) register_command log dump hook 0x7f066fc7a050 -324> 2015-10-19 16:59:15.606398 7f066c070940 5 asok(0x7f066fd06000) register_command log reopen hook 0x7f066fc7a050 -323> 2015-10-19 16:59:15.609949 7f066c070940 0 set uid:gid to 1000:1000 -322> 2015-10-19 16:59:15.610005 7f066c070940 0 ceph version 9.1.0-227-gc55f8d4 (c55f8d4300019bf2da1fe52edb0c2151cc8e3d2e), process ceph-mon, pid 2329 -321> 2015-10-19 16:59:15.611310 7f066c070940 5 asok(0x7f066fd06000) init /var/run/ceph/ceph-mon.ceph2.asok -320> 2015-10-19 16:59:15.611317 7f066c070940 5 asok(0x7f066fd06000) bind_and_listen /var/run/ceph/ceph-mon.ceph2.asok -319> 2015-10-19 16:59:15.611332 7f066c070940 5 asok(0x7f066fd06000) register_command 0 hook 0x7f066fc760b8 -318> 2015-10-19 16:59:15.611337 7f066c070940 5 asok(0x7f066fd06000) register_command version hook 0x7f066fc760b8 -317> 2015-10-19 16:59:15.611338 7f066c070940 5 asok(0x7f066fd06000) register_command git_version hook 0x7f066fc760b8 -316> 2015-10-19 16:59:15.611343 7f066c070940 5 asok(0x7f066fd06000) register_command help hook 0x7f066fc7a240 -315> 2015-10-19 16:59:15.611346 7f066c070940 5 asok(0x7f066fd06000) register_command get_command_descriptions hook 0x7f066fc7a230 -314> 2015-10-19 16:59:15.611375 7f0665151700 5 asok(0x7f066fd06000) entry start -313> 2015-10-19 16:59:15.620165 7f066c070940 0 starting mon.ceph2 rank 1 at 192.168.72.42:6789/0 mon_data /var/lib/ceph/mon/ceph-ceph2 fsid f47da131-dc71-4768-844c-e71bf68d4f03 -312> 2015-10-19 16:59:15.620203 7f066c070940 1 -- 192.168.72.42:6789/0 learned my addr 192.168.72.42:6789/0 -311> 2015-10-19 16:59:15.620206 7f066c070940 1 accepter.accepter.bind my_inst.addr is 192.168.72.42:6789/0 need_addr=0 -310> 2015-10-19 16:59:15.620244 7f066c070940 5 adding auth protocol: cephx -309> 2015-10-19 16:59:15.620247 7f066c070940 5 adding auth protocol: cephx -308> 2015-10-19 16:59:15.620260 7f066c070940 10 log_channel(cluster) update_config to_monitors: true to_syslog: false syslog_facility: daemon prio: info) -307> 2015-10-19 16:59:15.620263 7f066c070940 10 log_channel(audit) update_config to_monitors: true to_syslog: false syslog_facility: local0 prio: info) -306> 2015-10-19 16:59:15.620317 7f066c070940 1 mon.ceph2@-1(probing) e0 preinit fsid f47da131-dc71-4768-844c-e71bf68d4f03 -305> 2015-10-19 16:59:15.620360 7f066c070940 1 mon.ceph2@-1(probing) e0 initial_members ceph1,ceph2,ceph3, filtering seed monmap -304> 2015-10-19 16:59:15.620364 7f066c070940 1 removing noname-a 192.168.72.41:6789/0 -303> 2015-10-19 16:59:15.620371 7f066c070940 1 keeping ceph2 192.168.72.42:6789/0 -302> 2015-10-19 16:59:15.620372 7f066c070940 1 removing noname-c 192.168.72.43:6789/0 -301> 2015-10-19 16:59:15.620375 7f066c070940 1 adding ceph1 0.0.0.0:0/1 -300> 2015-10-19 16:59:15.620378 7f066c070940 1 adding ceph3 0.0.0.0:0/2 -299> 2015-10-19 16:59:15.620595 7f066c070940 2 auth: KeyRing::load: loaded key file /var/lib/ceph/mon/ceph-ceph2/keyring -298> 2015-10-19 16:59:15.620601 7f066c070940 5 asok(0x7f066fd06000) register_command mon_status hook 0x7f066fc7a2c0 -297> 2015-10-19 16:59:15.620605 7f066c070940 5 asok(0x7f066fd06000) register_command quorum_status hook 0x7f066fc7a2c0 -296> 2015-10-19 16:59:15.620607 7f066c070940 5 asok(0x7f066fd06000) register_command sync_force hook 0x7f066fc7a2c0 -295> 2015-10-19 16:59:15.620609 7f066c070940 5 asok(0x7f066fd06000) register_command add_bootstrap_peer_hint hook 0x7f066fc7a2c0 -294> 2015-10-19 16:59:15.620612 7f066c070940 5 asok(0x7f066fd06000) register_command quorum enter hook 0x7f066fc7a2c0 -293> 2015-10-19 16:59:15.620615 7f066c070940 5 asok(0x7f066fd06000) register_command quorum exit hook 0x7f066fc7a2c0 -292> 2015-10-19 16:59:15.620619 7f066c070940 5 asok(0x7f066fd06000) register_command ops hook 0x7f066fc7a2c0 -291> 2015-10-19 16:59:15.620626 7f066c070940 1 -- 192.168.72.42:6789/0 messenger.start -290> 2015-10-19 16:59:15.620653 7f066c070940 2 mon.ceph2@-1(probing) e0 init -289> 2015-10-19 16:59:15.620693 7f066c070940 1 accepter.accepter.start -288> 2015-10-19 16:59:15.620707 7f066c070940 0 mon.ceph2@-1(probing) e0 my rank is now 0 (was -1) -287> 2015-10-19 16:59:15.620710 7f066c070940 1 -- 192.168.72.42:6789/0 mark_down_all -286> 2015-10-19 16:59:15.620718 7f066c070940 1 -- 192.168.72.42:6789/0 --> mon.1 0.0.0.0:0/1 -- mon_probe(probe f47da131-dc71-4768-844c-e71bf68d4f03 name ceph2 new) v6 -- ?+0 0x7f066fd6c780 -285> 2015-10-19 16:59:15.620783 7f066c070940 1 -- 192.168.72.42:6789/0 --> mon.2 0.0.0.0:0/2 -- mon_probe(probe f47da131-dc71-4768-844c-e71bf68d4f03 name ceph2 new) v6 -- ?+0 0x7f066fd6d680 -284> 2015-10-19 16:59:15.620804 7f066c070940 1 -- 192.168.72.42:6789/0 --> mon.? 192.168.72.41:6789/0 -- mon_probe(probe f47da131-dc71-4768-844c-e71bf68d4f03 name ceph2 new) v6 -- ?+0 0x7f066fd6d400 -283> 2015-10-19 16:59:15.620833 7f066c070940 1 -- 192.168.72.42:6789/0 --> mon.? 192.168.72.43:6789/0 -- mon_probe(probe f47da131-dc71-4768-844c-e71bf68d4f03 name ceph2 new) v6 -- ?+0 0x7f066fd6d180 -282> 2015-10-19 16:59:15.620844 7f066c06e700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/1 pipe(0x7f066fe52000 sd=12 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97340).connect error 0.0.0.0:0/1, (111) Connection refused -281> 2015-10-19 16:59:15.620882 7f066c06e700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/1 pipe(0x7f066fe52000 sd=12 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97340).fault (111) Connection refused -280> 2015-10-19 16:59:15.620899 7f066c06e700 0 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/1 pipe(0x7f066fe52000 sd=12 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97340).fault -279> 2015-10-19 16:59:15.620901 7f066b698700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/2 pipe(0x7f066fe57000 sd=13 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc971e0).connect error 0.0.0.0:0/2, (111) Connection refused -278> 2015-10-19 16:59:15.620942 7f066b698700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/2 pipe(0x7f066fe57000 sd=13 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc971e0).fault (111) Connection refused -277> 2015-10-19 16:59:15.620957 7f066b698700 0 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/2 pipe(0x7f066fe57000 sd=13 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc971e0).fault -276> 2015-10-19 16:59:15.620949 7f066c06e700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/1 pipe(0x7f066fe52000 sd=12 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97340).connect error 0.0.0.0:0/1, (111) Connection refused -275> 2015-10-19 16:59:15.620969 7f066c06e700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/1 pipe(0x7f066fe52000 sd=12 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97340).fault (111) Connection refused -274> 2015-10-19 16:59:15.620994 7f066b698700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/2 pipe(0x7f066fe57000 sd=13 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc971e0).connect error 0.0.0.0:0/2, (111) Connection refused -273> 2015-10-19 16:59:15.621009 7f066b698700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/2 pipe(0x7f066fe57000 sd=13 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc971e0).fault (111) Connection refused -272> 2015-10-19 16:59:15.621142 7f0660cd8700 2 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066fe5c000 sd=23 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc96f20).connect error 192.168.72.43:6789/0, (111) Connection refused -271> 2015-10-19 16:59:15.621170 7f0660cd8700 2 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066fe5c000 sd=23 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc96f20).fault (111) Connection refused -270> 2015-10-19 16:59:15.621177 7f0660cd8700 0 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066fe5c000 sd=23 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc96f20).fault -269> 2015-10-19 16:59:15.621315 7f0660cd8700 2 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066fe5c000 sd=23 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc96f20).connect error 192.168.72.43:6789/0, (111) Connection refused -268> 2015-10-19 16:59:15.621339 7f0660cd8700 2 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066fe5c000 sd=23 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc96f20).fault (111) Connection refused -267> 2015-10-19 16:59:15.674795 7f0665151700 5 asok(0x7f066fd06000) AdminSocket: request 'get_command_descriptions' '' to 0x7f066fc7a230 returned 2165 bytes -266> 2015-10-19 16:59:15.679720 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd='mon_status' args=[]: dispatch -265> 2015-10-19 16:59:15.679729 7f0665151700 10 log_client _send_to_monlog to self -264> 2015-10-19 16:59:15.679731 7f0665151700 10 log_client log_queue is 1 last_log 1 sent 0 num 1 unsent 1 sending 1 -263> 2015-10-19 16:59:15.679734 7f0665151700 10 log_client will send 2015-10-19 16:59:15.679728 mon.0 192.168.72.42:6789/0 1 : audit [DBG] from='admin socket' entity='admin socket' cmd='mon_status' args=[]: dispatch -262> 2015-10-19 16:59:15.679757 7f0665151700 1 -- 192.168.72.42:6789/0 --> 192.168.72.42:6789/0 -- log(1 entries) v1 -- ?+0 0x7f066fcab8c0 con 0x7f066fc96840 -261> 2015-10-19 16:59:15.679815 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd=mon_status args=[]: finished -260> 2015-10-19 16:59:15.679819 7f0665151700 10 log_client _send_to_monlog to self -259> 2015-10-19 16:59:15.679820 7f0665151700 10 log_client log_queue is 2 last_log 2 sent 1 num 2 unsent 1 sending 1 -258> 2015-10-19 16:59:15.679815 7f06625dc700 1 -- 192.168.72.42:6789/0 <== mon.0 192.168.72.42:6789/0 0 ==== log(1 entries) v1 ==== 0+0+0 (0 0 0) 0x7f066fcab8c0 con 0x7f066fc96840 -257> 2015-10-19 16:59:15.679822 7f0665151700 10 log_client will send 2015-10-19 16:59:15.679819 mon.0 192.168.72.42:6789/0 2 : audit [DBG] from='admin socket' entity='admin socket' cmd=mon_status args=[]: finished -256> 2015-10-19 16:59:15.679850 7f0665151700 1 -- 192.168.72.42:6789/0 --> 192.168.72.42:6789/0 -- log(1 entries) v1 -- ?+0 0x7f066fcac400 con 0x7f066fc96840 -255> 2015-10-19 16:59:15.679869 7f06625dc700 5 -- op tracker -- seq: 1, time: 2015-10-19 16:59:15.679765, event: header_read, op: log(1 entries) -254> 2015-10-19 16:59:15.679896 7f06625dc700 5 -- op tracker -- seq: 1, time: 0.000000, event: throttled, op: log(1 entries) -253> 2015-10-19 16:59:15.679897 7f06625dc700 5 -- op tracker -- seq: 1, time: 0.000000, event: all_read, op: log(1 entries) -252> 2015-10-19 16:59:15.680036 7f06625dc700 5 -- op tracker -- seq: 1, time: 2015-10-19 16:59:15.679833, event: dispatched, op: log(1 entries) -251> 2015-10-19 16:59:15.680042 7f0665151700 5 asok(0x7f066fd06000) AdminSocket: request 'mon_status' '' to 0x7f066fc7a2c0 returned 859 bytes -250> 2015-10-19 16:59:15.680046 7f06625dc700 5 -- op tracker -- seq: 1, time: 2015-10-19 16:59:15.680046, event: mon:_ms_dispatch, op: log(1 entries) -249> 2015-10-19 16:59:15.680052 7f06625dc700 5 mon.ceph2@0(probing) e0 _ms_dispatch setting monitor caps on this connection -248> 2015-10-19 16:59:15.680060 7f06625dc700 5 -- op tracker -- seq: 1, time: 2015-10-19 16:59:15.680060, event: mon:dispatch_op, op: log(1 entries) -247> 2015-10-19 16:59:15.680063 7f06625dc700 5 -- op tracker -- seq: 1, time: 2015-10-19 16:59:15.680063, event: psvc:dispatch, op: log(1 entries) -246> 2015-10-19 16:59:15.680066 7f06625dc700 5 mon.ceph2@0(probing).paxos(paxos recovering c 0..0) is_readable = 0 - now=2015-10-19 16:59:15.680066 lease_expire=0.000000 has v0 lc 0 -245> 2015-10-19 16:59:15.680073 7f06625dc700 5 -- op tracker -- seq: 1, time: 2015-10-19 16:59:15.680073, event: logm:wait_for_readable, op: log(1 entries) -244> 2015-10-19 16:59:15.680076 7f06625dc700 5 -- op tracker -- seq: 1, time: 2015-10-19 16:59:15.680076, event: logm:wait_for_finished_proposal, op: log(1 entries) -243> 2015-10-19 16:59:15.680082 7f06625dc700 1 -- 192.168.72.42:6789/0 <== mon.0 192.168.72.42:6789/0 0 ==== log(1 entries) v1 ==== 0+0+0 (0 0 0) 0x7f066fcac400 con 0x7f066fc96840 -242> 2015-10-19 16:59:15.680089 7f06625dc700 5 -- op tracker -- seq: 2, time: 2015-10-19 16:59:15.679858, event: header_read, op: log(1 entries) -241> 2015-10-19 16:59:15.680091 7f06625dc700 5 -- op tracker -- seq: 2, time: 0.000000, event: throttled, op: log(1 entries) -240> 2015-10-19 16:59:15.680092 7f06625dc700 5 -- op tracker -- seq: 2, time: 0.000000, event: all_read, op: log(1 entries) -239> 2015-10-19 16:59:15.680096 7f06625dc700 5 -- op tracker -- seq: 2, time: 2015-10-19 16:59:15.680088, event: dispatched, op: log(1 entries) -238> 2015-10-19 16:59:15.680099 7f06625dc700 5 -- op tracker -- seq: 2, time: 2015-10-19 16:59:15.680099, event: mon:_ms_dispatch, op: log(1 entries) -237> 2015-10-19 16:59:15.680103 7f06625dc700 5 -- op tracker -- seq: 2, time: 2015-10-19 16:59:15.680103, event: mon:dispatch_op, op: log(1 entries) -236> 2015-10-19 16:59:15.680106 7f06625dc700 5 -- op tracker -- seq: 2, time: 2015-10-19 16:59:15.680106, event: psvc:dispatch, op: log(1 entries) -235> 2015-10-19 16:59:15.680110 7f06625dc700 5 mon.ceph2@0(probing).paxos(paxos recovering c 0..0) is_readable = 0 - now=2015-10-19 16:59:15.680110 lease_expire=0.000000 has v0 lc 0 -234> 2015-10-19 16:59:15.680113 7f06625dc700 5 -- op tracker -- seq: 2, time: 2015-10-19 16:59:15.680113, event: logm:wait_for_readable, op: log(1 entries) -233> 2015-10-19 16:59:15.680118 7f06625dc700 5 -- op tracker -- seq: 2, time: 2015-10-19 16:59:15.680118, event: logm:wait_for_finished_proposal, op: log(1 entries) -232> 2015-10-19 16:59:15.809404 7f0660dd9700 2 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7f066fe61000 sd=14 :36369 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97080).connect read reply (0) Success -231> 2015-10-19 16:59:15.809438 7f0660dd9700 2 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7f066fe61000 sd=14 :36369 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97080).fault (0) Success -230> 2015-10-19 16:59:15.809468 7f0660dd9700 0 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7f066fe61000 sd=14 :36369 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97080).fault -229> 2015-10-19 16:59:15.809626 7f0660dd9700 2 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7f066fe61000 sd=14 :36369 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97080).connect error 192.168.72.41:6789/0, (111) Connection refused -228> 2015-10-19 16:59:15.809663 7f0660dd9700 2 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7f066fe61000 sd=14 :36369 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97080).fault (111) Connection refused -227> 2015-10-19 16:59:15.821165 7f066c06e700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/1 pipe(0x7f066fe52000 sd=12 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97340).connect error 0.0.0.0:0/1, (111) Connection refused -226> 2015-10-19 16:59:15.821173 7f066b698700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/2 pipe(0x7f066fe57000 sd=13 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc971e0).connect error 0.0.0.0:0/2, (111) Connection refused -225> 2015-10-19 16:59:15.821197 7f066c06e700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/1 pipe(0x7f066fe52000 sd=12 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97340).fault (111) Connection refused -224> 2015-10-19 16:59:15.821203 7f066b698700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/2 pipe(0x7f066fe57000 sd=13 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc971e0).fault (111) Connection refused -223> 2015-10-19 16:59:15.821591 7f0660cd8700 2 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066fe5c000 sd=23 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc96f20).connect error 192.168.72.43:6789/0, (111) Connection refused -222> 2015-10-19 16:59:15.821611 7f0660cd8700 2 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066fe5c000 sd=23 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc96f20).fault (111) Connection refused -221> 2015-10-19 16:59:16.010026 7f0660dd9700 2 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7f066fe61000 sd=14 :36369 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97080).connect error 192.168.72.41:6789/0, (111) Connection refused -220> 2015-10-19 16:59:16.010063 7f0660dd9700 2 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7f066fe61000 sd=14 :36369 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97080).fault (111) Connection refused -219> 2015-10-19 16:59:16.221400 7f066b698700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/2 pipe(0x7f066fe57000 sd=13 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc971e0).connect error 0.0.0.0:0/2, (111) Connection refused -218> 2015-10-19 16:59:16.221401 7f066c06e700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/1 pipe(0x7f066fe52000 sd=12 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97340).connect error 0.0.0.0:0/1, (111) Connection refused -217> 2015-10-19 16:59:16.221438 7f066b698700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/2 pipe(0x7f066fe57000 sd=13 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc971e0).fault (111) Connection refused -216> 2015-10-19 16:59:16.221454 7f066c06e700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/1 pipe(0x7f066fe52000 sd=12 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97340).fault (111) Connection refused -215> 2015-10-19 16:59:16.221885 7f0660cd8700 2 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066fe5c000 sd=23 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc96f20).connect error 192.168.72.43:6789/0, (111) Connection refused -214> 2015-10-19 16:59:16.221921 7f0660cd8700 2 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066fe5c000 sd=23 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc96f20).fault (111) Connection refused -213> 2015-10-19 16:59:16.410396 7f0660dd9700 2 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7f066fe61000 sd=14 :36369 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97080).connect error 192.168.72.41:6789/0, (111) Connection refused -212> 2015-10-19 16:59:16.410432 7f0660dd9700 2 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7f066fe61000 sd=14 :36369 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97080).fault (111) Connection refused -211> 2015-10-19 16:59:16.737809 7f0665151700 5 asok(0x7f066fd06000) AdminSocket: request 'get_command_descriptions' '' to 0x7f066fc7a230 returned 2165 bytes -210> 2015-10-19 16:59:16.742414 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd='mon_status' args=[]: dispatch -209> 2015-10-19 16:59:16.742423 7f0665151700 10 log_client _send_to_monlog to self -208> 2015-10-19 16:59:16.742426 7f0665151700 10 log_client log_queue is 3 last_log 3 sent 2 num 3 unsent 1 sending 1 -207> 2015-10-19 16:59:16.742429 7f0665151700 10 log_client will send 2015-10-19 16:59:16.742422 mon.0 192.168.72.42:6789/0 3 : audit [DBG] from='admin socket' entity='admin socket' cmd='mon_status' args=[]: dispatch -206> 2015-10-19 16:59:16.742448 7f0665151700 1 -- 192.168.72.42:6789/0 --> 192.168.72.42:6789/0 -- log(1 entries) v1 -- ?+0 0x7f066fcabb00 con 0x7f066fc96840 -205> 2015-10-19 16:59:16.742507 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd=mon_status args=[]: finished -204> 2015-10-19 16:59:16.742512 7f0665151700 10 log_client _send_to_monlog to self -203> 2015-10-19 16:59:16.742512 7f0665151700 10 log_client log_queue is 4 last_log 4 sent 3 num 4 unsent 1 sending 1 -202> 2015-10-19 16:59:16.742507 7f06625dc700 1 -- 192.168.72.42:6789/0 <== mon.0 192.168.72.42:6789/0 0 ==== log(1 entries) v1 ==== 0+0+0 (0 0 0) 0x7f066fcabb00 con 0x7f066fc96840 -201> 2015-10-19 16:59:16.742515 7f0665151700 10 log_client will send 2015-10-19 16:59:16.742511 mon.0 192.168.72.42:6789/0 4 : audit [DBG] from='admin socket' entity='admin socket' cmd=mon_status args=[]: finished -200> 2015-10-19 16:59:16.742526 7f0665151700 1 -- 192.168.72.42:6789/0 --> 192.168.72.42:6789/0 -- log(1 entries) v1 -- ?+0 0x7f066fcabf80 con 0x7f066fc96840 -199> 2015-10-19 16:59:16.742564 7f06625dc700 5 -- op tracker -- seq: 3, time: 2015-10-19 16:59:16.742457, event: header_read, op: log(1 entries) -198> 2015-10-19 16:59:16.742574 7f06625dc700 5 -- op tracker -- seq: 3, time: 0.000000, event: throttled, op: log(1 entries) -197> 2015-10-19 16:59:16.742573 7f0665151700 5 asok(0x7f066fd06000) AdminSocket: request 'mon_status' '' to 0x7f066fc7a2c0 returned 859 bytes -196> 2015-10-19 16:59:16.742576 7f06625dc700 5 -- op tracker -- seq: 3, time: 0.000000, event: all_read, op: log(1 entries) -195> 2015-10-19 16:59:16.742578 7f06625dc700 5 -- op tracker -- seq: 3, time: 2015-10-19 16:59:16.742519, event: dispatched, op: log(1 entries) -194> 2015-10-19 16:59:16.742584 7f06625dc700 5 -- op tracker -- seq: 3, time: 2015-10-19 16:59:16.742584, event: mon:_ms_dispatch, op: log(1 entries) -193> 2015-10-19 16:59:16.742591 7f06625dc700 5 -- op tracker -- seq: 3, time: 2015-10-19 16:59:16.742591, event: mon:dispatch_op, op: log(1 entries) -192> 2015-10-19 16:59:16.742595 7f06625dc700 5 -- op tracker -- seq: 3, time: 2015-10-19 16:59:16.742595, event: psvc:dispatch, op: log(1 entries) -191> 2015-10-19 16:59:16.742611 7f06625dc700 5 mon.ceph2@0(probing).paxos(paxos recovering c 0..0) is_readable = 0 - now=2015-10-19 16:59:16.742612 lease_expire=0.000000 has v0 lc 0 -190> 2015-10-19 16:59:16.742628 7f06625dc700 5 -- op tracker -- seq: 3, time: 2015-10-19 16:59:16.742627, event: logm:wait_for_readable, op: log(1 entries) -189> 2015-10-19 16:59:16.742632 7f06625dc700 5 -- op tracker -- seq: 3, time: 2015-10-19 16:59:16.742632, event: logm:wait_for_finished_proposal, op: log(1 entries) -188> 2015-10-19 16:59:16.742636 7f06625dc700 1 -- 192.168.72.42:6789/0 <== mon.0 192.168.72.42:6789/0 0 ==== log(1 entries) v1 ==== 0+0+0 (0 0 0) 0x7f066fcabf80 con 0x7f066fc96840 -187> 2015-10-19 16:59:16.742643 7f06625dc700 5 -- op tracker -- seq: 4, time: 2015-10-19 16:59:16.742551, event: header_read, op: log(1 entries) -186> 2015-10-19 16:59:16.742645 7f06625dc700 5 -- op tracker -- seq: 4, time: 0.000000, event: throttled, op: log(1 entries) -185> 2015-10-19 16:59:16.742649 7f06625dc700 5 -- op tracker -- seq: 4, time: 0.000000, event: all_read, op: log(1 entries) -184> 2015-10-19 16:59:16.742650 7f06625dc700 5 -- op tracker -- seq: 4, time: 2015-10-19 16:59:16.742642, event: dispatched, op: log(1 entries) -183> 2015-10-19 16:59:16.742653 7f06625dc700 5 -- op tracker -- seq: 4, time: 2015-10-19 16:59:16.742653, event: mon:_ms_dispatch, op: log(1 entries) -182> 2015-10-19 16:59:16.742671 7f06625dc700 5 -- op tracker -- seq: 4, time: 2015-10-19 16:59:16.742671, event: mon:dispatch_op, op: log(1 entries) -181> 2015-10-19 16:59:16.742679 7f06625dc700 5 -- op tracker -- seq: 4, time: 2015-10-19 16:59:16.742679, event: psvc:dispatch, op: log(1 entries) -180> 2015-10-19 16:59:16.742686 7f06625dc700 5 mon.ceph2@0(probing).paxos(paxos recovering c 0..0) is_readable = 0 - now=2015-10-19 16:59:16.742687 lease_expire=0.000000 has v0 lc 0 -179> 2015-10-19 16:59:16.742694 7f06625dc700 5 -- op tracker -- seq: 4, time: 2015-10-19 16:59:16.742694, event: logm:wait_for_readable, op: log(1 entries) -178> 2015-10-19 16:59:16.742702 7f06625dc700 5 -- op tracker -- seq: 4, time: 2015-10-19 16:59:16.742702, event: logm:wait_for_finished_proposal, op: log(1 entries) -177> 2015-10-19 16:59:17.021633 7f066c06e700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/1 pipe(0x7f066fe52000 sd=12 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97340).connect error 0.0.0.0:0/1, (111) Connection refused -176> 2015-10-19 16:59:17.021659 7f066c06e700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/1 pipe(0x7f066fe52000 sd=12 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97340).fault (111) Connection refused -175> 2015-10-19 16:59:17.021650 7f066b698700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/2 pipe(0x7f066fe57000 sd=13 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc971e0).connect error 0.0.0.0:0/2, (111) Connection refused -174> 2015-10-19 16:59:17.021687 7f066b698700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/2 pipe(0x7f066fe57000 sd=13 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc971e0).fault (111) Connection refused -173> 2015-10-19 16:59:17.022209 7f0660cd8700 2 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066fe5c000 sd=23 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc96f20).connect error 192.168.72.43:6789/0, (111) Connection refused -172> 2015-10-19 16:59:17.022238 7f0660cd8700 2 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066fe5c000 sd=23 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc96f20).fault (111) Connection refused -171> 2015-10-19 16:59:17.210743 7f0660dd9700 2 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7f066fe61000 sd=14 :36369 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97080).connect error 192.168.72.41:6789/0, (111) Connection refused -170> 2015-10-19 16:59:17.210780 7f0660dd9700 2 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7f066fe61000 sd=14 :36369 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97080).fault (111) Connection refused -169> 2015-10-19 16:59:17.494428 7f0665151700 5 asok(0x7f066fd06000) AdminSocket: request 'get_command_descriptions' '' to 0x7f066fc7a230 returned 2165 bytes -168> 2015-10-19 16:59:17.499193 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd='mon_status' args=[]: dispatch -167> 2015-10-19 16:59:17.499200 7f0665151700 10 log_client _send_to_monlog to self -166> 2015-10-19 16:59:17.499201 7f0665151700 10 log_client log_queue is 5 last_log 5 sent 4 num 5 unsent 1 sending 1 -165> 2015-10-19 16:59:17.499203 7f0665151700 10 log_client will send 2015-10-19 16:59:17.499199 mon.0 192.168.72.42:6789/0 5 : audit [DBG] from='admin socket' entity='admin socket' cmd='mon_status' args=[]: dispatch -164> 2015-10-19 16:59:17.499217 7f0665151700 1 -- 192.168.72.42:6789/0 --> 192.168.72.42:6789/0 -- log(1 entries) v1 -- ?+0 0x7f066fcac1c0 con 0x7f066fc96840 -163> 2015-10-19 16:59:17.499254 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd=mon_status args=[]: finished -162> 2015-10-19 16:59:17.499257 7f0665151700 10 log_client _send_to_monlog to self -161> 2015-10-19 16:59:17.499258 7f0665151700 10 log_client log_queue is 6 last_log 6 sent 5 num 6 unsent 1 sending 1 -160> 2015-10-19 16:59:17.499259 7f0665151700 10 log_client will send 2015-10-19 16:59:17.499257 mon.0 192.168.72.42:6789/0 6 : audit [DBG] from='admin socket' entity='admin socket' cmd=mon_status args=[]: finished -159> 2015-10-19 16:59:17.499263 7f0665151700 1 -- 192.168.72.42:6789/0 --> 192.168.72.42:6789/0 -- log(1 entries) v1 -- ?+0 0x7f066fcacac0 con 0x7f066fc96840 -158> 2015-10-19 16:59:17.499276 7f0665151700 5 asok(0x7f066fd06000) AdminSocket: request 'mon_status' '' to 0x7f066fc7a2c0 returned 859 bytes -157> 2015-10-19 16:59:17.499304 7f06625dc700 1 -- 192.168.72.42:6789/0 <== mon.0 192.168.72.42:6789/0 0 ==== log(1 entries) v1 ==== 0+0+0 (0 0 0) 0x7f066fcac1c0 con 0x7f066fc96840 -156> 2015-10-19 16:59:17.499338 7f06625dc700 5 -- op tracker -- seq: 5, time: 2015-10-19 16:59:17.499222, event: header_read, op: log(1 entries) -155> 2015-10-19 16:59:17.499352 7f06625dc700 5 -- op tracker -- seq: 5, time: 0.000000, event: throttled, op: log(1 entries) -154> 2015-10-19 16:59:17.499354 7f06625dc700 5 -- op tracker -- seq: 5, time: 0.000000, event: all_read, op: log(1 entries) -153> 2015-10-19 16:59:17.499358 7f06625dc700 5 -- op tracker -- seq: 5, time: 2015-10-19 16:59:17.499333, event: dispatched, op: log(1 entries) -152> 2015-10-19 16:59:17.499366 7f06625dc700 5 -- op tracker -- seq: 5, time: 2015-10-19 16:59:17.499366, event: mon:_ms_dispatch, op: log(1 entries) -151> 2015-10-19 16:59:17.499375 7f06625dc700 5 -- op tracker -- seq: 5, time: 2015-10-19 16:59:17.499375, event: mon:dispatch_op, op: log(1 entries) -150> 2015-10-19 16:59:17.499384 7f06625dc700 5 -- op tracker -- seq: 5, time: 2015-10-19 16:59:17.499384, event: psvc:dispatch, op: log(1 entries) -149> 2015-10-19 16:59:17.499392 7f06625dc700 5 mon.ceph2@0(probing).paxos(paxos recovering c 0..0) is_readable = 0 - now=2015-10-19 16:59:17.499393 lease_expire=0.000000 has v0 lc 0 -148> 2015-10-19 16:59:17.499404 7f06625dc700 5 -- op tracker -- seq: 5, time: 2015-10-19 16:59:17.499404, event: logm:wait_for_readable, op: log(1 entries) -147> 2015-10-19 16:59:17.499427 7f06625dc700 5 -- op tracker -- seq: 5, time: 2015-10-19 16:59:17.499427, event: logm:wait_for_finished_proposal, op: log(1 entries) -146> 2015-10-19 16:59:17.499439 7f06625dc700 1 -- 192.168.72.42:6789/0 <== mon.0 192.168.72.42:6789/0 0 ==== log(1 entries) v1 ==== 0+0+0 (0 0 0) 0x7f066fcacac0 con 0x7f066fc96840 -145> 2015-10-19 16:59:17.499450 7f06625dc700 5 -- op tracker -- seq: 6, time: 2015-10-19 16:59:17.499266, event: header_read, op: log(1 entries) -144> 2015-10-19 16:59:17.499456 7f06625dc700 5 -- op tracker -- seq: 6, time: 0.000000, event: throttled, op: log(1 entries) -143> 2015-10-19 16:59:17.499458 7f06625dc700 5 -- op tracker -- seq: 6, time: 0.000000, event: all_read, op: log(1 entries) -142> 2015-10-19 16:59:17.499462 7f06625dc700 5 -- op tracker -- seq: 6, time: 2015-10-19 16:59:17.499448, event: dispatched, op: log(1 entries) -141> 2015-10-19 16:59:17.499469 7f06625dc700 5 -- op tracker -- seq: 6, time: 2015-10-19 16:59:17.499469, event: mon:_ms_dispatch, op: log(1 entries) -140> 2015-10-19 16:59:17.499476 7f06625dc700 5 -- op tracker -- seq: 6, time: 2015-10-19 16:59:17.499476, event: mon:dispatch_op, op: log(1 entries) -139> 2015-10-19 16:59:17.499484 7f06625dc700 5 -- op tracker -- seq: 6, time: 2015-10-19 16:59:17.499484, event: psvc:dispatch, op: log(1 entries) -138> 2015-10-19 16:59:17.499491 7f06625dc700 5 mon.ceph2@0(probing).paxos(paxos recovering c 0..0) is_readable = 0 - now=2015-10-19 16:59:17.499491 lease_expire=0.000000 has v0 lc 0 -137> 2015-10-19 16:59:17.499500 7f06625dc700 5 -- op tracker -- seq: 6, time: 2015-10-19 16:59:17.499500, event: logm:wait_for_readable, op: log(1 entries) -136> 2015-10-19 16:59:17.499507 7f06625dc700 5 -- op tracker -- seq: 6, time: 2015-10-19 16:59:17.499507, event: logm:wait_for_finished_proposal, op: log(1 entries) -135> 2015-10-19 16:59:17.611349 7f0665151700 5 asok(0x7f066fd06000) AdminSocket: request 'get_command_descriptions' '' to 0x7f066fc7a230 returned 2165 bytes -134> 2015-10-19 16:59:17.616543 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd='mon_status' args=[]: dispatch -133> 2015-10-19 16:59:17.616549 7f0665151700 10 log_client _send_to_monlog to self -132> 2015-10-19 16:59:17.616550 7f0665151700 10 log_client log_queue is 7 last_log 7 sent 6 num 7 unsent 1 sending 1 -131> 2015-10-19 16:59:17.616567 7f0665151700 10 log_client will send 2015-10-19 16:59:17.616548 mon.0 192.168.72.42:6789/0 7 : audit [DBG] from='admin socket' entity='admin socket' cmd='mon_status' args=[]: dispatch -130> 2015-10-19 16:59:17.616582 7f0665151700 1 -- 192.168.72.42:6789/0 --> 192.168.72.42:6789/0 -- log(1 entries) v1 -- ?+0 0x7f066fcacd00 con 0x7f066fc96840 -129> 2015-10-19 16:59:17.616619 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd=mon_status args=[]: finished -128> 2015-10-19 16:59:17.616621 7f0665151700 10 log_client _send_to_monlog to self -127> 2015-10-19 16:59:17.616621 7f0665151700 10 log_client log_queue is 8 last_log 8 sent 7 num 8 unsent 1 sending 1 -126> 2015-10-19 16:59:17.616623 7f0665151700 10 log_client will send 2015-10-19 16:59:17.616620 mon.0 192.168.72.42:6789/0 8 : audit [DBG] from='admin socket' entity='admin socket' cmd=mon_status args=[]: finished -125> 2015-10-19 16:59:17.616643 7f0665151700 1 -- 192.168.72.42:6789/0 --> 192.168.72.42:6789/0 -- log(1 entries) v1 -- ?+0 0x7f066fcac640 con 0x7f066fc96840 -124> 2015-10-19 16:59:17.616662 7f0665151700 5 asok(0x7f066fd06000) AdminSocket: request 'mon_status' '' to 0x7f066fc7a2c0 returned 859 bytes -123> 2015-10-19 16:59:17.616666 7f06625dc700 1 -- 192.168.72.42:6789/0 <== mon.0 192.168.72.42:6789/0 0 ==== log(1 entries) v1 ==== 0+0+0 (0 0 0) 0x7f066fcacd00 con 0x7f066fc96840 -122> 2015-10-19 16:59:17.616698 7f06625dc700 5 -- op tracker -- seq: 7, time: 2015-10-19 16:59:17.616587, event: header_read, op: log(1 entries) -121> 2015-10-19 16:59:17.616713 7f06625dc700 5 -- op tracker -- seq: 7, time: 0.000000, event: throttled, op: log(1 entries) -120> 2015-10-19 16:59:17.616717 7f06625dc700 5 -- op tracker -- seq: 7, time: 0.000000, event: all_read, op: log(1 entries) -119> 2015-10-19 16:59:17.616721 7f06625dc700 5 -- op tracker -- seq: 7, time: 2015-10-19 16:59:17.616692, event: dispatched, op: log(1 entries) -118> 2015-10-19 16:59:17.616731 7f06625dc700 5 -- op tracker -- seq: 7, time: 2015-10-19 16:59:17.616731, event: mon:_ms_dispatch, op: log(1 entries) -117> 2015-10-19 16:59:17.616740 7f06625dc700 5 -- op tracker -- seq: 7, time: 2015-10-19 16:59:17.616739, event: mon:dispatch_op, op: log(1 entries) -116> 2015-10-19 16:59:17.616747 7f06625dc700 5 -- op tracker -- seq: 7, time: 2015-10-19 16:59:17.616747, event: psvc:dispatch, op: log(1 entries) -115> 2015-10-19 16:59:17.616756 7f06625dc700 5 mon.ceph2@0(probing).paxos(paxos recovering c 0..0) is_readable = 0 - now=2015-10-19 16:59:17.616757 lease_expire=0.000000 has v0 lc 0 -114> 2015-10-19 16:59:17.616767 7f06625dc700 5 -- op tracker -- seq: 7, time: 2015-10-19 16:59:17.616767, event: logm:wait_for_readable, op: log(1 entries) -113> 2015-10-19 16:59:17.616774 7f06625dc700 5 -- op tracker -- seq: 7, time: 2015-10-19 16:59:17.616774, event: logm:wait_for_finished_proposal, op: log(1 entries) -112> 2015-10-19 16:59:17.616784 7f06625dc700 1 -- 192.168.72.42:6789/0 <== mon.0 192.168.72.42:6789/0 0 ==== log(1 entries) v1 ==== 0+0+0 (0 0 0) 0x7f066fcac640 con 0x7f066fc96840 -111> 2015-10-19 16:59:17.616800 7f06625dc700 5 -- op tracker -- seq: 8, time: 2015-10-19 16:59:17.616650, event: header_read, op: log(1 entries) -110> 2015-10-19 16:59:17.616807 7f06625dc700 5 -- op tracker -- seq: 8, time: 0.000000, event: throttled, op: log(1 entries) -109> 2015-10-19 16:59:17.616809 7f06625dc700 5 -- op tracker -- seq: 8, time: 0.000000, event: all_read, op: log(1 entries) -108> 2015-10-19 16:59:17.616812 7f06625dc700 5 -- op tracker -- seq: 8, time: 2015-10-19 16:59:17.616793, event: dispatched, op: log(1 entries) -107> 2015-10-19 16:59:17.616820 7f06625dc700 5 -- op tracker -- seq: 8, time: 2015-10-19 16:59:17.616820, event: mon:_ms_dispatch, op: log(1 entries) -106> 2015-10-19 16:59:17.616827 7f06625dc700 5 -- op tracker -- seq: 8, time: 2015-10-19 16:59:17.616826, event: mon:dispatch_op, op: log(1 entries) -105> 2015-10-19 16:59:17.616833 7f06625dc700 5 -- op tracker -- seq: 8, time: 2015-10-19 16:59:17.616833, event: psvc:dispatch, op: log(1 entries) -104> 2015-10-19 16:59:17.616840 7f06625dc700 5 mon.ceph2@0(probing).paxos(paxos recovering c 0..0) is_readable = 0 - now=2015-10-19 16:59:17.616841 lease_expire=0.000000 has v0 lc 0 -103> 2015-10-19 16:59:17.616849 7f06625dc700 5 -- op tracker -- seq: 8, time: 2015-10-19 16:59:17.616849, event: logm:wait_for_readable, op: log(1 entries) -102> 2015-10-19 16:59:17.616855 7f06625dc700 5 -- op tracker -- seq: 8, time: 2015-10-19 16:59:17.616855, event: logm:wait_for_finished_proposal, op: log(1 entries) -101> 2015-10-19 16:59:17.620784 7f0662ddd700 4 mon.ceph2@0(probing) e0 probe_timeout 0x7f066fc7a2a0 -100> 2015-10-19 16:59:17.620822 7f0662ddd700 5 -- op tracker -- seq: 1, time: 2015-10-19 16:59:17.620822, event: callback retry, op: log(1 entries) -99> 2015-10-19 16:59:17.620838 7f0662ddd700 5 -- op tracker -- seq: 1, time: 2015-10-19 16:59:17.620838, event: psvc:dispatch, op: log(1 entries) -98> 2015-10-19 16:59:17.620844 7f0662ddd700 5 mon.ceph2@0(probing).paxos(paxos recovering c 0..0) is_readable = 0 - now=2015-10-19 16:59:17.620846 lease_expire=0.000000 has v0 lc 0 -97> 2015-10-19 16:59:17.620856 7f0662ddd700 5 -- op tracker -- seq: 1, time: 2015-10-19 16:59:17.620856, event: logm:wait_for_readable, op: log(1 entries) -96> 2015-10-19 16:59:17.620865 7f0662ddd700 5 -- op tracker -- seq: 1, time: 2015-10-19 16:59:17.620865, event: logm:wait_for_finished_proposal, op: log(1 entries) -95> 2015-10-19 16:59:17.620873 7f0662ddd700 5 -- op tracker -- seq: 2, time: 2015-10-19 16:59:17.620872, event: callback retry, op: log(1 entries) -94> 2015-10-19 16:59:17.620880 7f0662ddd700 5 -- op tracker -- seq: 2, time: 2015-10-19 16:59:17.620880, event: psvc:dispatch, op: log(1 entries) -93> 2015-10-19 16:59:17.620887 7f0662ddd700 5 mon.ceph2@0(probing).paxos(paxos recovering c 0..0) is_readable = 0 - now=2015-10-19 16:59:17.620887 lease_expire=0.000000 has v0 lc 0 -92> 2015-10-19 16:59:17.620895 7f0662ddd700 5 -- op tracker -- seq: 2, time: 2015-10-19 16:59:17.620895, event: logm:wait_for_readable, op: log(1 entries) -91> 2015-10-19 16:59:17.620900 7f0662ddd700 5 -- op tracker -- seq: 2, time: 2015-10-19 16:59:17.620900, event: logm:wait_for_finished_proposal, op: log(1 entries) -90> 2015-10-19 16:59:17.620908 7f0662ddd700 5 -- op tracker -- seq: 3, time: 2015-10-19 16:59:17.620908, event: callback retry, op: log(1 entries) -89> 2015-10-19 16:59:17.620915 7f0662ddd700 5 -- op tracker -- seq: 3, time: 2015-10-19 16:59:17.620915, event: psvc:dispatch, op: log(1 entries) -88> 2015-10-19 16:59:17.620923 7f0662ddd700 5 mon.ceph2@0(probing).paxos(paxos recovering c 0..0) is_readable = 0 - now=2015-10-19 16:59:17.620923 lease_expire=0.000000 has v0 lc 0 -87> 2015-10-19 16:59:17.620931 7f0662ddd700 5 -- op tracker -- seq: 3, time: 2015-10-19 16:59:17.620931, event: logm:wait_for_readable, op: log(1 entries) -86> 2015-10-19 16:59:17.620938 7f0662ddd700 5 -- op tracker -- seq: 3, time: 2015-10-19 16:59:17.620937, event: logm:wait_for_finished_proposal, op: log(1 entries) -85> 2015-10-19 16:59:17.620946 7f0662ddd700 5 -- op tracker -- seq: 4, time: 2015-10-19 16:59:17.620946, event: callback retry, op: log(1 entries) -84> 2015-10-19 16:59:17.620953 7f0662ddd700 5 -- op tracker -- seq: 4, time: 2015-10-19 16:59:17.620953, event: psvc:dispatch, op: log(1 entries) -83> 2015-10-19 16:59:17.620960 7f0662ddd700 5 mon.ceph2@0(probing).paxos(paxos recovering c 0..0) is_readable = 0 - now=2015-10-19 16:59:17.620960 lease_expire=0.000000 has v0 lc 0 -82> 2015-10-19 16:59:17.620968 7f0662ddd700 5 -- op tracker -- seq: 4, time: 2015-10-19 16:59:17.620968, event: logm:wait_for_readable, op: log(1 entries) -81> 2015-10-19 16:59:17.620975 7f0662ddd700 5 -- op tracker -- seq: 4, time: 2015-10-19 16:59:17.620975, event: logm:wait_for_finished_proposal, op: log(1 entries) -80> 2015-10-19 16:59:17.620982 7f0662ddd700 5 -- op tracker -- seq: 5, time: 2015-10-19 16:59:17.620982, event: callback retry, op: log(1 entries) -79> 2015-10-19 16:59:17.620989 7f0662ddd700 5 -- op tracker -- seq: 5, time: 2015-10-19 16:59:17.620989, event: psvc:dispatch, op: log(1 entries) -78> 2015-10-19 16:59:17.620996 7f0662ddd700 5 mon.ceph2@0(probing).paxos(paxos recovering c 0..0) is_readable = 0 - now=2015-10-19 16:59:17.620997 lease_expire=0.000000 has v0 lc 0 -77> 2015-10-19 16:59:17.621004 7f0662ddd700 5 -- op tracker -- seq: 5, time: 2015-10-19 16:59:17.621004, event: logm:wait_for_readable, op: log(1 entries) -76> 2015-10-19 16:59:17.621011 7f0662ddd700 5 -- op tracker -- seq: 5, time: 2015-10-19 16:59:17.621011, event: logm:wait_for_finished_proposal, op: log(1 entries) -75> 2015-10-19 16:59:17.621018 7f0662ddd700 5 -- op tracker -- seq: 6, time: 2015-10-19 16:59:17.621018, event: callback retry, op: log(1 entries) -74> 2015-10-19 16:59:17.621025 7f0662ddd700 5 -- op tracker -- seq: 6, time: 2015-10-19 16:59:17.621025, event: psvc:dispatch, op: log(1 entries) -73> 2015-10-19 16:59:17.621032 7f0662ddd700 5 mon.ceph2@0(probing).paxos(paxos recovering c 0..0) is_readable = 0 - now=2015-10-19 16:59:17.621033 lease_expire=0.000000 has v0 lc 0 -72> 2015-10-19 16:59:17.621040 7f0662ddd700 5 -- op tracker -- seq: 6, time: 2015-10-19 16:59:17.621040, event: logm:wait_for_readable, op: log(1 entries) -71> 2015-10-19 16:59:17.621047 7f0662ddd700 5 -- op tracker -- seq: 6, time: 2015-10-19 16:59:17.621047, event: logm:wait_for_finished_proposal, op: log(1 entries) -70> 2015-10-19 16:59:17.621053 7f0662ddd700 5 -- op tracker -- seq: 7, time: 2015-10-19 16:59:17.621053, event: callback retry, op: log(1 entries) -69> 2015-10-19 16:59:17.621059 7f0662ddd700 5 -- op tracker -- seq: 7, time: 2015-10-19 16:59:17.621059, event: psvc:dispatch, op: log(1 entries) -68> 2015-10-19 16:59:17.621064 7f0662ddd700 5 mon.ceph2@0(probing).paxos(paxos recovering c 0..0) is_readable = 0 - now=2015-10-19 16:59:17.621064 lease_expire=0.000000 has v0 lc 0 -67> 2015-10-19 16:59:17.621072 7f0662ddd700 5 -- op tracker -- seq: 7, time: 2015-10-19 16:59:17.621071, event: logm:wait_for_readable, op: log(1 entries) -66> 2015-10-19 16:59:17.621079 7f0662ddd700 5 -- op tracker -- seq: 7, time: 2015-10-19 16:59:17.621079, event: logm:wait_for_finished_proposal, op: log(1 entries) -65> 2015-10-19 16:59:17.621086 7f0662ddd700 5 -- op tracker -- seq: 8, time: 2015-10-19 16:59:17.621085, event: callback retry, op: log(1 entries) -64> 2015-10-19 16:59:17.621093 7f0662ddd700 5 -- op tracker -- seq: 8, time: 2015-10-19 16:59:17.621093, event: psvc:dispatch, op: log(1 entries) -63> 2015-10-19 16:59:17.621099 7f0662ddd700 5 mon.ceph2@0(probing).paxos(paxos recovering c 0..0) is_readable = 0 - now=2015-10-19 16:59:17.621100 lease_expire=0.000000 has v0 lc 0 -62> 2015-10-19 16:59:17.621107 7f0662ddd700 5 -- op tracker -- seq: 8, time: 2015-10-19 16:59:17.621107, event: logm:wait_for_readable, op: log(1 entries) -61> 2015-10-19 16:59:17.621114 7f0662ddd700 5 -- op tracker -- seq: 8, time: 2015-10-19 16:59:17.621114, event: logm:wait_for_finished_proposal, op: log(1 entries) -60> 2015-10-19 16:59:17.621128 7f0662ddd700 1 -- 192.168.72.42:6789/0 --> mon.1 0.0.0.0:0/1 -- mon_probe(probe f47da131-dc71-4768-844c-e71bf68d4f03 name ceph2 new) v6 -- ?+0 0x7f066fd6d900 -59> 2015-10-19 16:59:17.621164 7f0662ddd700 1 -- 192.168.72.42:6789/0 --> mon.2 0.0.0.0:0/2 -- mon_probe(probe f47da131-dc71-4768-844c-e71bf68d4f03 name ceph2 new) v6 -- ?+0 0x7f066fd6de00 -58> 2015-10-19 16:59:17.621178 7f0662ddd700 1 -- 192.168.72.42:6789/0 --> mon.? 192.168.72.41:6789/0 -- mon_probe(probe f47da131-dc71-4768-844c-e71bf68d4f03 name ceph2 new) v6 -- ?+0 0x7f066fd6db80 -57> 2015-10-19 16:59:17.621191 7f0662ddd700 1 -- 192.168.72.42:6789/0 --> mon.? 192.168.72.43:6789/0 -- mon_probe(probe f47da131-dc71-4768-844c-e71bf68d4f03 name ceph2 new) v6 -- ?+0 0x7f066fd6e580 -56> 2015-10-19 16:59:17.621242 7f066b698700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/2 pipe(0x7f066fe57000 sd=12 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc971e0).connect error 0.0.0.0:0/2, (111) Connection refused -55> 2015-10-19 16:59:17.621263 7f066b698700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/2 pipe(0x7f066fe57000 sd=12 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc971e0).fault (111) Connection refused -54> 2015-10-19 16:59:17.621254 7f066c06e700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/1 pipe(0x7f066fe52000 sd=14 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97340).connect error 0.0.0.0:0/1, (111) Connection refused -53> 2015-10-19 16:59:17.621286 7f066c06e700 2 -- 192.168.72.42:6789/0 >> 0.0.0.0:0/1 pipe(0x7f066fe52000 sd=14 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97340).fault (111) Connection refused -52> 2015-10-19 16:59:17.621337 7f0660dd9700 2 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7f066fe61000 sd=13 :36369 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97080).connect error 192.168.72.41:6789/0, (111) Connection refused -51> 2015-10-19 16:59:17.621355 7f0660cd8700 2 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066fe5c000 sd=23 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc96f20).connect error 192.168.72.43:6789/0, (111) Connection refused -50> 2015-10-19 16:59:17.621374 7f0660dd9700 2 -- 192.168.72.42:6789/0 >> 192.168.72.41:6789/0 pipe(0x7f066fe61000 sd=13 :36369 s=1 pgs=0 cs=0 l=0 c=0x7f066fc97080).fault (111) Connection refused -49> 2015-10-19 16:59:17.621379 7f0660cd8700 2 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066fe5c000 sd=23 :0 s=1 pgs=0 cs=0 l=0 c=0x7f066fc96f20).fault (111) Connection refused -48> 2015-10-19 16:59:17.801169 7f0665151700 5 asok(0x7f066fd06000) AdminSocket: request 'get_command_descriptions' '' to 0x7f066fc7a230 returned 2165 bytes -47> 2015-10-19 16:59:17.806207 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd='mon_status' args=[]: dispatch -46> 2015-10-19 16:59:17.806229 7f0665151700 10 log_client _send_to_monlog to self -45> 2015-10-19 16:59:17.806231 7f0665151700 10 log_client log_queue is 9 last_log 9 sent 8 num 9 unsent 1 sending 1 -44> 2015-10-19 16:59:17.806234 7f0665151700 10 log_client will send 2015-10-19 16:59:17.806228 mon.0 192.168.72.42:6789/0 9 : audit [DBG] from='admin socket' entity='admin socket' cmd='mon_status' args=[]: dispatch -43> 2015-10-19 16:59:17.806257 7f0665151700 1 -- 192.168.72.42:6789/0 --> 192.168.72.42:6789/0 -- log(1 entries) v1 -- ?+0 0x7f066fcac880 con 0x7f066fc96840 -42> 2015-10-19 16:59:17.806320 7f0665151700 0 log_channel(audit) log [DBG] : from='admin socket' entity='admin socket' cmd=mon_status args=[]: finished -41> 2015-10-19 16:59:17.806326 7f0665151700 10 log_client _send_to_monlog to self -40> 2015-10-19 16:59:17.806327 7f0665151700 10 log_client log_queue is 10 last_log 10 sent 9 num 10 unsent 1 sending 1 -39> 2015-10-19 16:59:17.806320 7f06625dc700 1 -- 192.168.72.42:6789/0 <== mon.0 192.168.72.42:6789/0 0 ==== log(1 entries) v1 ==== 0+0+0 (0 0 0) 0x7f066fcac880 con 0x7f066fc96840 -38> 2015-10-19 16:59:17.806330 7f0665151700 10 log_client will send 2015-10-19 16:59:17.806324 mon.0 192.168.72.42:6789/0 10 : audit [DBG] from='admin socket' entity='admin socket' cmd=mon_status args=[]: finished -37> 2015-10-19 16:59:17.806360 7f0665151700 1 -- 192.168.72.42:6789/0 --> 192.168.72.42:6789/0 -- log(1 entries) v1 -- ?+0 0x7f066fcad600 con 0x7f066fc96840 -36> 2015-10-19 16:59:17.806385 7f06625dc700 5 -- op tracker -- seq: 9, time: 2015-10-19 16:59:17.806265, event: header_read, op: log(1 entries) -35> 2015-10-19 16:59:17.806404 7f06625dc700 5 -- op tracker -- seq: 9, time: 0.000000, event: throttled, op: log(1 entries) -34> 2015-10-19 16:59:17.806414 7f06625dc700 5 -- op tracker -- seq: 9, time: 0.000000, event: all_read, op: log(1 entries) -33> 2015-10-19 16:59:17.806394 7f0665151700 5 asok(0x7f066fd06000) AdminSocket: request 'mon_status' '' to 0x7f066fc7a2c0 returned 859 bytes -32> 2015-10-19 16:59:17.806416 7f06625dc700 5 -- op tracker -- seq: 9, time: 2015-10-19 16:59:17.806341, event: dispatched, op: log(1 entries) -31> 2015-10-19 16:59:17.806427 7f06625dc700 5 -- op tracker -- seq: 9, time: 2015-10-19 16:59:17.806427, event: mon:_ms_dispatch, op: log(1 entries) -30> 2015-10-19 16:59:17.806435 7f06625dc700 5 -- op tracker -- seq: 9, time: 2015-10-19 16:59:17.806435, event: mon:dispatch_op, op: log(1 entries) -29> 2015-10-19 16:59:17.806444 7f06625dc700 5 -- op tracker -- seq: 9, time: 2015-10-19 16:59:17.806444, event: psvc:dispatch, op: log(1 entries) -28> 2015-10-19 16:59:17.806453 7f06625dc700 5 mon.ceph2@0(probing).paxos(paxos recovering c 0..0) is_readable = 0 - now=2015-10-19 16:59:17.806454 lease_expire=0.000000 has v0 lc 0 -27> 2015-10-19 16:59:17.806465 7f06625dc700 5 -- op tracker -- seq: 9, time: 2015-10-19 16:59:17.806465, event: logm:wait_for_readable, op: log(1 entries) -26> 2015-10-19 16:59:17.806472 7f06625dc700 5 -- op tracker -- seq: 9, time: 2015-10-19 16:59:17.806472, event: logm:wait_for_finished_proposal, op: log(1 entries) -25> 2015-10-19 16:59:17.806479 7f06625dc700 1 -- 192.168.72.42:6789/0 <== mon.0 192.168.72.42:6789/0 0 ==== log(1 entries) v1 ==== 0+0+0 (0 0 0) 0x7f066fcad600 con 0x7f066fc96840 -24> 2015-10-19 16:59:17.806490 7f06625dc700 5 -- op tracker -- seq: 10, time: 2015-10-19 16:59:17.806368, event: header_read, op: log(1 entries) -23> 2015-10-19 16:59:17.806497 7f06625dc700 5 -- op tracker -- seq: 10, time: 0.000000, event: throttled, op: log(1 entries) -22> 2015-10-19 16:59:17.806499 7f06625dc700 5 -- op tracker -- seq: 10, time: 0.000000, event: all_read, op: log(1 entries) -21> 2015-10-19 16:59:17.806502 7f06625dc700 5 -- op tracker -- seq: 10, time: 2015-10-19 16:59:17.806489, event: dispatched, op: log(1 entries) -20> 2015-10-19 16:59:17.806509 7f06625dc700 5 -- op tracker -- seq: 10, time: 2015-10-19 16:59:17.806509, event: mon:_ms_dispatch, op: log(1 entries) -19> 2015-10-19 16:59:17.806516 7f06625dc700 5 -- op tracker -- seq: 10, time: 2015-10-19 16:59:17.806516, event: mon:dispatch_op, op: log(1 entries) -18> 2015-10-19 16:59:17.806523 7f06625dc700 5 -- op tracker -- seq: 10, time: 2015-10-19 16:59:17.806523, event: psvc:dispatch, op: log(1 entries) -17> 2015-10-19 16:59:17.806528 7f06625dc700 5 mon.ceph2@0(probing).paxos(paxos recovering c 0..0) is_readable = 0 - now=2015-10-19 16:59:17.806529 lease_expire=0.000000 has v0 lc 0 -16> 2015-10-19 16:59:17.806537 7f06625dc700 5 -- op tracker -- seq: 10, time: 2015-10-19 16:59:17.806537, event: logm:wait_for_readable, op: log(1 entries) -15> 2015-10-19 16:59:17.806567 7f06625dc700 5 -- op tracker -- seq: 10, time: 2015-10-19 16:59:17.806566, event: logm:wait_for_finished_proposal, op: log(1 entries) -14> 2015-10-19 16:59:18.479067 7f06603d6700 1 -- 192.168.72.42:6789/0 >> :/0 pipe(0x7f066feb2000 sd=24 :6789 s=0 pgs=0 cs=0 l=0 c=0x7f066fc974a0).accept sd=24 192.168.72.43:56186/0 -13> 2015-10-19 16:59:18.479309 7f06603d6700 0 cephx: verify_authorizer could not decrypt ticket info: error: NSS AES final round failed: -8190 -12> 2015-10-19 16:59:18.479320 7f06603d6700 0 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066feb2000 sd=24 :6789 s=0 pgs=0 cs=0 l=0 c=0x7f066fc974a0).accept connect_seq 0 vs existing 0 state connecting -11> 2015-10-19 16:59:18.479442 7f06603d6700 2 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066feb2000 sd=24 :6789 ??=0 l=0 c=0x7 fc97 f? f? -10> 2015-10-19 16:59:18.479701 7f06603d6700 1 -- 192.168.72.42:6789/0 >> :/0 pipe(0x7f066feb7000 sd=24 :6789 s=0 pgs=0 cs=0 l=0 c=0x7f066fc97600).accept sd=24 192.168.72.43:56190/0 -9> 2015-10-19 16:59:18.479948 7f06603d6700 0 cephx: verify_authorizer could not decrypt ticket info: error: NSS AES final round failed: -8190 -8> 2015-10-19 16:59:18.479958 7f06603d6700 0 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066feb7000 sd=24 :6789 s=0 pgs=0 cs=0 l=0 c=0x7f066fc97600).accept connect_seq 0 vs existing 0 state connecting -7> 2015-10-19 16:59:18.479986 7f0660cd8700 0 cephx: verify_reply couldn't decrypt with error: error decoding block for decryption -6> 2015-10-19 16:59:18.479992 7f0660cd8700 0 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066fe5c000 sd=23 :53881 s=1 pgs=0 cs=0 l=0 c=0x7f066fc96f20).failed verifying authorize reply -5> 2015-10-19 16:59:18.479990 7f06603d6700 2 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066feb7000 sd=24 :6789 ??=0 l=0 c=0x7 fc97 ? ? -4> 2015-10-19 16:59:18.480004 7f0660cd8700 2 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066fe5c000 sd=23 :53881 s=1 pgs=0 cs=0 l=0 c=0x7f066fc96f20).fault (107) Transport endpoint is not connected -3> 2015-10-19 16:59:18.480376 7f06603d6700 1 -- 192.168.72.42:6789/0 >> :/0 pipe(0x7f066feb2000 sd=24 :6789 s=0 pgs=0 cs=0 l=0 c=0x7f066fc974a0).accept sd=24 192.168.72.43:56191/0 -2> 2015-10-19 16:59:18.604786 7f06603d6700 2 -- 192.168.72.42:6789/0 >> 192.168.72.43:6789/0 pipe(0x7f066feb2000 sd=24 :6789 s=4 pgs=0 cs=0 l=0 c=0x7f066fc974a0).fault (0) Success -1> 2015-10-19 16:59:18.640151 7f06603d6700 1 -- 192.168.72.42:6789/0 >> :/0 pipe(0x7f066feb7000 sd=24 :6789 s=0 pgs=0 cs=0 l=0 c=0x7f066fc97760).accept sd=24 192.168.72.43:56196/0 0> 2015-10-19 16:59:18.643689 7f06603d6700 -1 *** Caught signal (Segmentation fault) ** in thread 7f06603d6700 ceph version 9.1.0-227-gc55f8d4 (c55f8d4300019bf2da1fe52edb0c2151cc8e3d2e) 1: (()+0x68d75a) [0x7f066bd2975a] 2: (()+0x10340) [0x7f066a538340] 3: (PK11_DoesMechanism()+0x5f) [0x7f066a2404bf] 4: (()+0x33027) [0x7f066a221027] 5: (()+0x4cf2a) [0x7f066a23af2a] 6: (()+0x4cf7b) [0x7f066a23af7b] 7: (PK11_CreateContextBySymKey()+0x22) [0x7f066a21fe62] 8: (()+0x374407) [0x7f066ba10407] 9: (CryptoAESKeyHandler::decrypt(ceph::buffer::list const&, ceph::buffer::list&, std::string*) const+0x2a) [0x7f066ba111ca] 10: (void decode_decrypt_enc_bl<CephXServiceTicketInfo>(CephContext*, CephXServiceTicketInfo&, CryptoKey, ceph::buffer::list&, std::string&)+0xba) [0x7f066ba0874a] 11: (cephx_verify_authorizer(CephContext*, KeyStore*, ceph::buffer::list::iterator&, CephXServiceTicketInfo&, ceph::buffer::list&)+0x394) [0x7f066ba03a94] 12: (Monitor::ms_verify_authorizer(Connection*, int, int, ceph::buffer::list&, ceph::buffer::list&, bool&, CryptoKey&)+0x409) [0x7f066b8b3179] 13: (SimpleMessenger::verify_authorizer(Connection*, int, int, ceph::buffer::list&, ceph::buffer::list&, bool&, CryptoKey&)+0x7f) [0x7f066bad955f] 14: (Pipe::accept()+0x1e51) [0x7f066bc9f191] 15: (Pipe::reader()+0x19ff) [0x7f066bca3e1f] 16: (Pipe::Reader::entry()+0xd) [0x7f066bcabccd] 17: (()+0x8182) [0x7f066a530182] 18: (clone()+0x6d) [0x7f0668a9d47d] 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