Project

General

Profile

Actions

Bug #37499

closed

AsyncConnection stuck

Added by xiaocheng wang over 5 years ago. Updated almost 5 years ago.

Status:
Resolved
Priority:
Normal
Category:
AsyncMessenger
Target version:
% Done:

0%

Source:
Community (dev)
Tags:
Backport:
mimic,luminous
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Files

CPEPH-LOG.txt (14.8 KB) CPEPH-LOG.txt xiaocheng wang, 12/01/2018 06:43 AM
Actions #1

Updated by xiaocheng wang over 5 years ago

2018-11-29 16:18:24.313933 7f1c7b919700 10 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept my proto 13, their proto 13
2018-11-29 16:18:24.313935 7f1c7b919700 10 mon.MON118@0(leader) e3 ms_verify_authorizer 10.252.253.119:6789/0 mon protocol 2
2018-11-29 16:18:24.313952 7f1c7b919700 10 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept setting up session_security.
2018-11-29 16:18:24.313957 7f1c7b919700 10 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept existing 0x565156585800.gseq 47057 <= 62458, looks ok
2018-11-29 16:18:24.313959 7f1c7b919700 0 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept connect_seq 14 vs existing csq=14 existing_state=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY
2018-11-29 16:18:24.313961 7f1c7b919700 10 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept connection race, existing 0x565156585800.cseq 14 == 14, sending WAIT
2018-11-29 16:18:24.313968 7f1c7b919700 10 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0)._try_send sent bytes 62 remaining bytes 0
2018-11-29 16:18:24.314020 7f1c7b919700 1 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG pgs=0 cs=0 l=0).read_bulk peer close file descriptor 10
2018-11-29 16:18:24.314023 7f1c7b919700 1 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG pgs=0 cs=0 l=0).read_until read failed
2018-11-29 16:18:24.314026 7f1c7b919700 1 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG pgs=0 cs=0 l=0)._process_connection read connect msg failed
2018-11-29 16:18:24.314033 7f1c7b919700 10 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG pgs=0 cs=0 l=0).fault with nothing to send, going to standby

Actions #2

Updated by xiaocheng wang over 5 years ago

2018-11-29 15:40:09.197750 7f4a114af700 1 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY_AUTH pgs=43339 cs=14 l=0).handle_connect_reply connect got WAIT (connection race)
2018-11-29 15:40:24.197882 7f4a114af700 1 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY_AUTH pgs=43339 cs=14 l=0).handle_connect_reply connect got WAIT (connection race)
2018-11-29 15:40:39.199293 7f4a114af700 1 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY_AUTH pgs=43339 cs=14 l=0).handle_connect_reply connect got WAIT (connection race)
2018-11-29 15:40:54.201877 7f4a114af700 1 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY_AUTH pgs=43339 cs=14 l=0).handle_connect_reply connect got WAIT (connection race)
2018-11-29 15:41:09.206144 7f4a114af700 1 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY_AUTH pgs=43339 cs=14 l=0).handle_connect_reply connect got WAIT (connection race)
2018-11-29 15:41:24.206343 7f4a114af700 1 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY_AUTH pgs=43339 cs=14 l=0).handle_connect_reply connect got WAIT (connection race)

Actions #3

Updated by Greg Farnum over 5 years ago

  • Status changed from New to Closed

This one-sided output just indicates the connection tried but the other end wasn't cooperating. If it's still an issue, please set "debug ms = 20" on both sides, try again, and post both logs.

Actions #4

Updated by xiaocheng wang over 5 years ago

MON118
10.252.253.118

2018-11-29 16:18:18.071753 7f1c7f921700 10 mon.MON118@0(electing).paxosservice(health 6091..6337) restart
2018-11-29 16:18:18.071897 7f1c7f921700 1 -- 10.252.253.118:6789/0 _send_message--> mon.1 10.252.253.119:6789/0 -- election(bd03b9ee-3273-4a4f-91e0-7ce427fcb388 propose 50777) v7 -- ?+0 0x565167714f00
2018-11-29 16:18:18.071903 7f1c7f921700 1 -- 10.252.253.118:6789/0 --> 10.252.253.119:6789/0 -- election(bd03b9ee-3273-4a4f-91e0-7ce427fcb388 propose 50777) v7 -- 0x565167714f00 con 0
2018-11-29 16:18:18.071913 7f1c7f921700 1 -- 10.252.253.118:6789/0 _send_message--> mon.2 10.252.253.130:6789/0 -- election(bd03b9ee-3273-4a4f-91e0-7ce427fcb388 propose 50777) v7 -- ?+0 0x565159790900
2018-11-29 16:18:18.071914 7f1c7c11a700 10 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565156585800 :-1 s=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY pgs=47057 cs=14 l=0).handle_write
2018-11-29 16:18:18.071919 7f1c7f921700 1 -- 10.252.253.118:6789/0 --> 10.252.253.130:6789/0 -- election(bd03b9ee-3273-4a4f-91e0-7ce427fcb388 propose 50777) v7 -- 0x565159790900 con 0
2018-11-29 16:18:18.071921 7f1c7c11a700 10 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565156585800 :-1 s=l pgs=47057 cs=14 l=0)._try_send sent bytes 0 remaining bytes 0
2018-11-29 16:18:18.071927 7f1c7f921700 10 -- 10.252.253.118:6789/0 dispatch_throttle_release 533 to dispatch throttler 533/536870912
2018-11-29 16:18:18.071928 7f1c7c91b700 10 -- 10.252.253.118:6789/0 >> 10.252.253.130:6789/0 conn(0x565156587000 :-1 s=STATE_OPEN pgs=42481 cs=17 l=0).handle_write
2018-11-29 16:18:18.071934 7f1c7f921700 1 -- 10.252.253.118:6789/0 <== mon.0 10.252.253.118:6789/0 0 ==== log(last 50151) v1 ==== 0+0+0 (0 0 0) 0x5651612a72c0 con 0x56515687e000
2018-11-29 16:18:18.071940 7f1c7f921700 20 mon.MON118@0(electing) e3 _ms_dispatch existing session 0x565155fbd980 for mon.0 10.252.253.118:6789/0
2018-11-29 16:18:18.071943 7f1c7f921700 20 mon.MON118@0(electing) e3 caps allow *
2018-11-29 16:18:18.071944 7f1c7f921700 20 is_capable service=mon command= read on cap allow *

2018-11-29 16:18:24.313588 7f1c7b919700 10 Processor -- accept accepted incoming on sd 10
2018-11-29 16:18:24.313593 7f1c7b919700 10 -- 10.252.253.118:6789/0 >> - conn(0x565161da6000 :-1 s=STATE_NONE pgs=0 cs=0 l=0).accept sd=10
2018-11-29 16:18:24.313612 7f1c7b919700 1 -- 10.252.253.118:6789/0 >> - conn(0x565161da6000 :6789 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=10
2018-11-29 16:18:24.313623 7f1c7b919700 10 -
10.252.253.118:6789/0 >> - conn(0x565161da6000 :6789 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._try_send sent bytes 281 remaining bytes 0
2018-11-29 16:18:24.313626 7f1c7b919700 10 -- 10.252.253.118:6789/0 >> - conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0)._process_connection write banner and addr done:
2018-11-29 16:18:24.313725 7f1c7b919700 10 -
10.252.253.118:6789/0 >> - conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0)._process_connection accept peer addr is 10.252.253.119:6789/0
2018-11-29 16:18:24.313764 7f1c7b919700 10 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0)._process_connection accept of host_type 1, policy.lossy=0 policy.server=0 policy.standby=1 policy.resetcheck=1
2018-11-29 16:18:24.313773 7f1c7b919700 10 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept my proto 13, their proto 13
2018-11-29 16:18:24.313776 7f1c7b919700 10 mon.MON118@0(leader) e3 ms_verify_authorizer 10.252.253.119:6789/0 mon protocol 2
2018-11-29 16:18:24.313826 7f1c7b919700 0 mon.MON118@0(leader) e3 ms_verify_authorizer bad authorizer from mon 10.252.253.119:6789/0
2018-11-29 16:18:24.313832 7f1c7b919700 0 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg: challenging authorizer
2018-11-29 16:18:24.313838 7f1c7b919700 10 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0)._try_send sent bytes 58 remaining bytes 0
2018-11-29 16:18:24.313929 7f1c7b919700 10 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0)._process_connection accept of host_type 1, policy.lossy=0 policy.server=0 policy.standby=1 policy.resetcheck=1
2018-11-29 16:18:24.313933 7f1c7b919700 10 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept my proto 13, their proto 13
2018-11-29 16:18:24.313935 7f1c7b919700 10 mon.MON118@0(leader) e3 ms_verify_authorizer 10.252.253.119:6789/0 mon protocol 2
2018-11-29 16:18:24.313952 7f1c7b919700 10 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept setting up session_security.
2018-11-29 16:18:24.313957 7f1c7b919700 10 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept existing 0x565156585800.gseq 47057 <= 62458, looks ok
2018-11-29 16:18:24.313959 7f1c7b919700 0 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept connect_seq 14 vs existing csq=14 existing_state=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY
2018-11-29 16:18:24.313961 7f1c7b919700 10 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept connection race, existing 0x565156585800.cseq 14 == 14, sending WAIT
2018-11-29 16:18:24.313968 7f1c7b919700 10 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0)._try_send sent bytes 62 remaining bytes 0
2018-11-29 16:18:24.314020 7f1c7b919700 1 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG pgs=0 cs=0 l=0).read_bulk peer close file descriptor 10
2018-11-29 16:18:24.314023 7f1c7b919700 1 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG pgs=0 cs=0 l=0).read_until read failed
2018-11-29 16:18:24.314026 7f1c7b919700 1 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG pgs=0 cs=0 l=0)._process_connection read connect msg failed
2018-11-29 16:18:24.314033 7f1c7b919700 10 -- 10.252.253.118:6789/0 >> 10.252.253.119:6789/0 conn(0x565161da6000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG pgs=0 cs=0 l=0).fault with nothing to send, going to standby

-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
MON119
10.252.253.119

2018-11-29 13:51:39.485325 7f4a114af700 0 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_OPEN pgs=1799 cs=1 l=0).fault initiating reconnect
2018-11-29 13:51:45.514862 7f4a10cae700 0 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=1799 cs=2 l=0).handle_connect_msg: challenging authorizer
2018-11-29 13:52:23.229339 7f4a10cae700 0 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_OPEN pgs=41615 cs=3 l=0).fault initiating reconnect
2018-11-29 13:52:29.848002 7f4a11cb0700 0 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=41615 cs=4 l=0).handle_connect_msg: challenging authorizer
2018-11-29 13:53:04.637339 7f4a11cb0700 0 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_OPEN pgs=41673 cs=5 l=0).fault initiating reconnect
2018-11-29 13:53:36.776084 7f4a114af700 0 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=41673 cs=6 l=0).handle_connect_msg: challenging authorizer
2018-11-29 13:53:59.869327 7f4a114af700 0 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_OPEN pgs=41887 cs=7 l=0).fault initiating reconnect
2018-11-29 13:54:33.453320 7f4a114af700 0 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_OPEN pgs=41930 cs=9 l=0).fault initiating reconnect
2018-11-29 13:54:49.272217 7f4a114af700 0 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=41930 cs=10 l=0).handle_connect_msg: challenging authorizer
....

2018-11-29 16:18:39.317237 7f4a114af700 10 NetHandler reconnect reconnect: Operation already in progress
2018-11-29 16:18:39.317250 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_RE pgs=43339 cs=14 l=0)._process_connection nonblock connect inprogress
2018-11-29 16:18:39.317458 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_RE pgs=43339 cs=14 l=0)._process_connection connect successfully, ready to send banner
2018-11-29 16:18:39.317472 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_RE pgs=43339 cs=14 l=0)._try_send sent bytes 9 remaining bytes 0
2018-11-29 16:18:39.317478 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY pgs=43339 cs=14 l=0)._process_connection connect write banner done: 10.252.253.118:6789/0
2018-11-29 16:18:39.317485 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY pgs=43339 cs=14 l=0).handle_write
2018-11-29 16:18:39.317491 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY pgs=43339 cs=14 l=0)._try_send sent bytes 0 remaining bytes 0
2018-11-29 16:18:39.317601 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_WAIT_BANNER_AND_IDENTIFY pgs=43339 cs=14 l=0)._try_send sent bytes 136 remaining bytes 0
2018-11-29 16:18:39.317607 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_SEND_CONNECT_MSG pgs=43339 cs=14 l=0)._process_connection connect sent my addr 10.252.253.119:6789/0
2018-11-29 16:18:39.317611 7f4a114af700 10 mon.MON119@1(electing) e3 ms_get_authorizer for mon
2018-11-29 16:18:39.317661 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_SEND_CONNECT_MSG pgs=43339 cs=14 l=0)._process_connection connect_msg.authorizer_len=158 protocol=2
2018-11-29 16:18:39.317666 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_SEND_CONNECT_MSG pgs=43339 cs=14 l=0)._process_connection connect sending gseq=62460 cseq=14 proto=13
2018-11-29 16:18:39.317674 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_SEND_CONNECT_MSG pgs=43339 cs=14 l=0)._try_send sent bytes 191 remaining bytes 0
2018-11-29 16:18:39.317680 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY pgs=43339 cs=14 l=0).handle_write
2018-11-29 16:18:39.317682 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY pgs=43339 cs=14 l=0)._try_send sent bytes 0 remaining bytes 0
2018-11-29 16:18:39.317806 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY_AUTH pgs=43339 cs=14 l=0)._process_connection reply.authorizer_len=32
2018-11-29 16:18:39.317812 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY_AUTH pgs=43339 cs=14 l=0)._process_connection connect got auth challenge
2018-11-29 16:18:39.317821 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_SEND_CONNECT_MSG pgs=43339 cs=14 l=0)._process_connection connect_msg.authorizer_len=158 protocol=2
2018-11-29 16:18:39.317825 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_SEND_CONNECT_MSG pgs=43339 cs=14 l=0)._process_connection connect sending gseq=62460 cseq=14 proto=13
2018-11-29 16:18:39.317832 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_SEND_CONNECT_MSG pgs=43339 cs=14 l=0)._try_send sent bytes 191 remaining bytes 0
2018-11-29 16:18:39.317837 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY pgs=43339 cs=14 l=0).handle_write
2018-11-29 16:18:39.317840 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY pgs=43339 cs=14 l=0)._try_send sent bytes 0 remaining bytes 0
2018-11-29 16:18:39.317934 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY_AUTH pgs=43339 cs=14 l=0)._process_connection reply.authorizer_len=36
2018-11-29 16:18:39.317944 7f4a114af700 1 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY_AUTH pgs=43339 cs=14 l=0).handle_connect_reply connect got WAIT (connection race)
2018-11-29 16:18:39.317947 7f4a114af700 1 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_WAIT pgs=43339 cs=14 l=0).process enter wait state, failing
2018-11-29 16:18:39.317958 7f4a114af700 10 -- 10.252.253.119:6789/0 >> 10.252.253.118:6789/0 conn(0x5603245ea000 :-1 s=STATE_CONNECTING pgs=43339 cs=14 l=0).fault waiting 15.000000
2018-11-29 16:18:39.527127 7f4a174bb700 11 mon.MON119@1(electing) e3 tick
2018-11-29 16:18:39.527144 7f4a174bb700 20 mon.MON119@1(electing) e3 sync_trim_providers

Actions #5

Updated by Patrick Donnelly over 5 years ago

  • Status changed from Closed to Fix Under Review
  • Assignee set to xiaocheng wang
  • Target version set to v14.0.0
  • Start date deleted (12/01/2018)
  • Source set to Community (dev)
  • Backport set to mimic,luminous
  • Pull request ID set to 25482
Actions #6

Updated by Greg Farnum about 5 years ago

  • Project changed from Ceph to Messengers
  • Category deleted (msgr)
Actions #7

Updated by Greg Farnum about 5 years ago

  • Category set to AsyncMessenger
Actions #8

Updated by Jason Dillaman almost 5 years ago

  • Status changed from Fix Under Review to Resolved
  • Pull request ID set to 27337
Actions

Also available in: Atom PDF