Bug #18996
Updated by Kefu Chai about 7 years ago
<pre> 2017-02-19T15:59:24.646 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: [ RUN ] LibRadosMiscConnectFailure.ConnectFailure 2017-02-19T15:59:24.646 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.616382 7f7846e9c800 -1 WARNING: all dangerous dangero us and experimental features are enabled. 2017-02-19T15:59:24.646 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.617083 7f7846e9c800 -1 asok(0x55859e06e840) AdminSocketConfigObs::init: failed: AdminSocket::bind_and_listen: failed to bind the UNIX domain socket to '/var/run/ceph/ceph-client.admin.18540.asok': (17) File exists 2017-02-19T15:59:24.646 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.617097 7f7846e9c800 10 monclient: build_ini tial_monmap 2017-02-19T15:59:24.646 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.632744 7f7846e9c800 1 librados: starting msgr at - 2017-02-19T15:59:24.646 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.632901 7f7846e9c800 1 librados: starting objecter 2017-02-19T15:59:24.646 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.633560 7f7846e9c800 1 Processor -- start 2017-02-19T15:59:24.646 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.633798 7f7846e9c800 1 -- - start start 2017-02-19T15:59:24.646 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.633906 7f7846e9c800 1 librados: setting wa nted keys 2017-02-19T15:59:24.646 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.634008 7f7846e9c800 1 librados: calling monclient init 2017-02-19T15:59:24.647 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.634106 7f7846e9c800 10 monclient: init 2017-02-19T15:59:24.647 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.634323 7f7846e9c800 10 monclient: auth_supported 2 method cephx 2017-02-19T15:59:24.647 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.636604 7f7846e9c800 10 monclient: _reopen_session rank -1 2017-02-19T15:59:24.647 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.637165 7f7846e9c800 10 monclient(hunting):picked mon.b con 0x55859e13d390 addr 172.21.4.128:6789/0 2017-02-19T15:59:24.647 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.637612 7f7846e9c800 10 monclient(hunting):picked mon.c con 0x55859e140a00 addr 172.21.3.116:6790/0 2017-02-19T15:59:24.647 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.637990 7f7832ffd700 1 -- 172.21.3.116:0/145937711 learned_addr learned my addr 172.21.3.116:0/145937711 2017-02-19T15:59:24.647 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.638443 7f7846e9c800 1 -- 172.21.3.116:0/145937711 --> 172.21.4.128:6789/0 -- auth(proto 0 30 bytes epoch 0) v1 -- 0x55859e114ba0 con 0 2017-02-19T15:59:24.647 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.638589 7f7846e9c800 1 -- 172.21.3.116:0/145937711 --> 172.21.3.116:6790/0 -- auth(proto 0 30 bytes epoch 0) v1 -- 0x55859e1151a0 con 0 2017-02-19T15:59:24.647 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.638859 7f7846e9c800 10 monclient(hunting): _renew_subs 2017-02-19T15:59:24.648 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.639011 7f7846e9c800 10 monclient(hunting): authenticate will time out at 2017-02-19 15:59:24.639011 2017-02-19T15:59:24.648 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.643307 7f7831ffb700 10 client.?.objecter ms_handle_connect 0x55859e13d390 2017-02-19T15:59:24.648 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.643335 7f7831ffb700 10 client.?.objecter resend_mon_ops 2017-02-19T15:59:24.648 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.643854 7f7831ffb700 10 client.?.objecter ms_handle_connect 0x55859e140a00 2017-02-19T15:59:24.648 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.643863 7f7831ffb700 10 client.?.objecter resend_mon_ops 2017-02-19T15:59:24.649 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.644605 7f7831ffb700 1 -- 172.21.3.116:0/145937711 <== mon.2 172.21.3.116:6790/0 1 ==== mon_map magic: 0 v1 ==== 355+0+0 (691045880 0 0) 0x7f7820001060 con 0x55859e140a00 2017-02-19T15:59:24.649 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.644628 7f7831ffb700 10 monclient(hunting): handle_monmap mon_map magic: 0 v1 2017-02-19T15:59:24.649 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.644644 7f7831ffb700 10 monclient(hunting): got monmap 2, mon.c is now rank 2 2017-02-19T15:59:24.649 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.644646 7f7831ffb700 10 monclient(hunting): dump: 2017-02-19T15:59:24.650 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: epoch 2 2017-02-19T15:59:24.650 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: fsid cfc25076-e2a6-4177-8c77-007ed278d2be 2017-02-19T15:59:24.650 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: last_changed 2017-02-19 15:58:49.923743 2017-02-19T15:59:24.651 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: created 2017-02-19 15:58:01.626783 2017-02-19T15:59:24.651 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 0: 172.21.3.116:6789/0 mon.a 2017-02-19T15:59:24.651 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 1: 172.21.4.128:6789/0 mon.b 2017-02-19T15:59:24.651 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2: 172.21.3.116:6790/0 mon.c 2017-02-19T15:59:24.651 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19T15:59:24.651 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.645052 7f7831ffb700 1 -- 172.21.3.116:0/145937711 <== mon.2 172.21.3.116:6790/0 2 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 33+0+0 (2942301640 0 0) 0x7f7820001380 con 0x55859e140a00 2017-02-19T15:59:24.651 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.645078 7f7831ffb700 10 monclient(hunting): my global_id is 4241 2017-02-19T15:59:24.651 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.645167 7f7831ffb700 1 -- 172.21.3.116:0/145937711 --> 172.21.3.116:6790/0 -- auth(proto 2 32 bytes epoch 0) v1 -- 0x7f7818001ab0 con 0 2017-02-19T15:59:24.651 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.645503 7f7831ffb700 1 -- 172.21.3.116:0/145937711 <== mon.1 172.21.4.128:6789/0 1 ==== mon_map magic: 0 v1 ==== 355+0+0 (691045880 0 0) 0x7f78280010e0 con 0x55859e13d390 2017-02-19T15:59:24.651 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.645516 7f7831ffb700 10 monclient(hunting): handle_monmap mon_map magic: 0 v1 2017-02-19T15:59:24.652 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.645525 7f7831ffb700 10 monclient(hunting): got monmap 2, mon.b is now rank 1 2017-02-19T15:59:24.652 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.645527 7f7831ffb700 10 monclient(hunting): dump: 2017-02-19T15:59:24.652 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: epoch 2 2017-02-19T15:59:24.652 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: fsid cfc25076-e2a6-4177-8c77-007ed278d2be 2017-02-19T15:59:24.652 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: last_changed 2017-02-19 15:58:49.923743 2017-02-19T15:59:24.652 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: created 2017-02-19 15:58:01.626783 2017-02-19T15:59:24.652 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 0: 172.21.3.116:6789/0 mon.a 2017-02-19T15:59:24.652 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 1: 172.21.4.128:6789/0 mon.b 2017-02-19T15:59:24.653 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2: 172.21.3.116:6790/0 mon.c 2017-02-19T15:59:24.653 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19T15:59:24.653 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.646346 7f7831ffb700 1 -- 172.21.3.116:0/145937711 <== mon.1 172.21.4.128:6789/0 2 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 33+0+0 (3666301376 0 0) 0x7f7828001390 con 0x55859e13d390 2017-02-19T15:59:24.653 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.646367 7f7831ffb700 10 monclient(hunting): my global_id is 4234 2017-02-19T15:59:24.653 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.646425 7f7831ffb700 1 -- 172.21.3.116:0/145937711 --> 172.21.4.128:6789/0 -- auth(proto 2 32 bytes epoch 0) v1 -- 0x7f7818003ac0 con 0 2017-02-19T15:59:24.653 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.646856 7f7831ffb700 1 -- 172.21.3.116:0/145937711 <== mon.2 172.21.3.116:6790/0 3 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 206+0+0 (3290750594 0 0) 0x7f7820000d00 con 0x55859e140a00 2017-02-19T15:59:24.653 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.646928 7f7831ffb700 1 -- 172.21.3.116:0/145937711 --> 172.21.3.116:6790/0 -- auth(proto 2 165 bytes epoch 0) v1 -- 0x7f7818001f10 con 0 2017-02-19T15:59:24.653 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.647810 7f7831ffb700 1 -- 172.21.3.116:0/145937711 <== mon.1 172.21.4.128:6789/0 3 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 206+0+0 (2224928937 0 0) 0x7f7828001010 con 0x55859e13d390 2017-02-19T15:59:24.653 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.647883 7f7831ffb700 1 -- 172.21.3.116:0/145937711 --> 172.21.4.128:6789/0 -- auth(proto 2 165 bytes epoch 0) v1 -- 0x7f7818002630 con 0 2017-02-19T15:59:24.657 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.648274 7f7831ffb700 1 -- 172.21.3.116:0/145937711 <== mon.2 172.21.3.116:6790/0 4 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 564+0+0 (3969616104 0 0) 0x7f78200012b0 con 0x55859e140a00 2017-02-19T15:59:24.658 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.648379 7f7831ffb700 1 -- 172.21.3.116:0/145937711 >> 172.21.4.128:6789/0 conn(0x55859e13d390 :-1 s=STATE_OPEN pgs=59 cs=1 l=1).mark_down 2017-02-19T15:59:24.658 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.648414 7f7831ffb700 1 monclient: found mon.c 2017-02-19T15:59:24.658 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.648417 7f7831ffb700 10 monclient: _send_mon_message to mon.c at 172.21.3.116:6790/0 2017-02-19T15:59:24.658 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.648420 7f7831ffb700 1 -- 172.21.3.116:0/145937711 --> 172.21.3.116:6790/0 -- mon_subscribe({monmap=0+}) v2 -- 0x55859e114ea0 con 0 2017-02-19T15:59:24.658 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.648434 7f7831ffb700 20 monclient: _check_auth_rotating not needed by client.admin 2017-02-19T15:59:24.659 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.652818 7f7846e9c800 5 monclient: authenticate success, global_id 4241 2017-02-19T15:59:24.659 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.653744 7f7846e9c800 10 monclient: _renew_subs 2017-02-19T15:59:24.659 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.653899 7f7846e9c800 10 monclient: _send_mon_message to mon.c at 172.21.3.116:6790/0 2017-02-19T15:59:24.659 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.654003 7f7846e9c800 1 -- 172.21.3.116:0/145937711 --> 172.21.3.116:6790/0 -- mon_subscribe({mgrmap=0+}) v2 -- 0x55859e1151a0 con 0 2017-02-19T15:59:24.659 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.654232 7f7846e9c800 10 client.4241.objecter _maybe_request_map subscribing (onetime) to next osd map 2017-02-19T15:59:24.660 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.654389 7f7846e9c800 10 monclient: _renew_subs 2017-02-19T15:59:24.660 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.654496 7f7846e9c800 10 monclient: _send_mon_message to mon.c at 172.21.3.116:6790/0 2017-02-19T15:59:24.660 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.654614 7f7846e9c800 1 -- 172.21.3.116:0/145937711 --> 172.21.3.116:6790/0 -- mon_subscribe({osdmap=0}) v2 -- 0x55859e112200 con 0 2017-02-19T15:59:24.660 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: 2017-02-19 15:59:24.654836 7f7846e9c800 1 librados: init done 2017-02-19T15:59:24.660 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: /build/ceph-12.0.0-538-g8ac3230/src/test/librados/misc.cc:69: Failure 2017-02-19T15:59:24.661 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: Expected: (0) != (rados_connect(cluster)), actual: 0 vs 0 2017-02-19T15:59:24.661 INFO:tasks.workunit.client.0.mira012.stdout: api_misc: [ FAILED ] LibRadosMiscConnectFailure.ConnectFailure (68 ms) </pre> the connect succeeded. see http://pulpito.ceph.com/kchai-2017-02-18_17:57:32-rados-wip-kefu-testing---basic-mira/831453/