Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Doubt when set up two peer urls. #9054

Closed
ghost opened this issue Dec 20, 2017 · 12 comments
Closed

Doubt when set up two peer urls. #9054

ghost opened this issue Dec 20, 2017 · 12 comments

Comments

@ghost
Copy link

ghost commented Dec 20, 2017

I set up two peer urls on each etcd node in my cluster. For some reason, one peer url can't access by other notes.
Normally etcd can switch to the accessible one, print log like this:

2017-12-20 02:21:18.068065 I | etcdserver/membership: added member a9efae717f838092 [https://ETCD-206-8-2-9160-10-2-31-0.grm-etcd.manage.svc.cluster.grm:11006 https://ETCD-206-8-2-9160-10-2-31-1.grm-etcd.manage.svc.cluster.grm:11006] to cluster a10f21f554347d1a
2017-12-20 02:21:18.068134 I | rafthttp: starting peer a9efae717f838092...
2017-12-20 02:21:18.068181 I | rafthttp: started HTTP pipelining with peer a9efae717f838092
2017-12-20 02:21:18.068522 I | rafthttp: started streaming with peer a9efae717f838092 (writer)
2017-12-20 02:21:18.073874 I | rafthttp: started streaming with peer a9efae717f838092 (writer)
2017-12-20 02:21:18.074419 I | rafthttp: started peer a9efae717f838092
2017-12-20 02:21:18.074449 I | rafthttp: started streaming with peer a9efae717f838092 (stream MsgApp v2 reader)
2017-12-20 02:21:18.074476 I | rafthttp: added peer a9efae717f838092
2017-12-20 02:21:18.074500 I | rafthttp: started streaming with peer a9efae717f838092 (stream Message reader)
2017-12-20 02:21:18.646646 I | rafthttp: peer a9efae717f838092 became active
2017-12-20 02:21:18.646686 I | rafthttp: established a TCP streaming connection with peer a9efae717f838092 (stream Message writer)
2017-12-20 02:21:18.647062 I | rafthttp: established a TCP streaming connection with peer a9efae717f838092 (stream MsgApp v2 writer)
2017-12-20 02:21:21.175899 E | rafthttp: failed to dial a9efae717f838092 on stream MsgApp v2 (dial tcp 160.10.2.31:11006: i/o timeout)
2017-12-20 02:21:21.175947 I | rafthttp: peer a9efae717f838092 became inactive
2017-12-20 02:21:21.293895 I | rafthttp: peer a9efae717f838092 became active
2017-12-20 02:21:21.293949 I | rafthttp: established a TCP streaming connection with peer a9efae717f838092 (stream Message reader)
2017-12-20 02:21:21.299375 I | rafthttp: established a TCP streaming connection with peer a9efae717f838092 (stream MsgApp v2 reader)

From logs above, the member a9efae717f838092 added by member API, will became active finally, though its state change: active--inactive--active.

Abnormally, it didn't change active once, and the log is:

2017-12-16 07:28:36.178307 I | etcdserver/membership: added member 6248f0f145a2047 [https://ETCD-206-8-2-9160-10-2-31-0.grm-etcd.manage.svc.cluster.grm:11006 https://ETCD-206-8-2-9160-10-2-31-1.grm-etcd.manage.svc.cluster.grm:11006] to cluster a10f21f554347d1a
2017-12-16 07:28:36.178383 I | rafthttp: starting peer 6248f0f145a2047...
2017-12-16 07:28:36.178406 I | rafthttp: started HTTP pipelining with peer 6248f0f145a2047
2017-12-16 07:28:36.179127 I | rafthttp: started streaming with peer 6248f0f145a2047 (writer)
2017-12-16 07:28:36.179152 I | rafthttp: started peer 6248f0f145a2047
2017-12-16 07:28:36.179170 I | rafthttp: started streaming with peer 6248f0f145a2047 (writer)
2017-12-16 07:28:36.179184 I | rafthttp: added peer 6248f0f145a2047
2017-12-16 07:28:36.179204 I | rafthttp: started streaming with peer 6248f0f145a2047 (stream MsgApp v2 reader)
2017-12-16 07:28:36.179284 I | rafthttp: started streaming with peer 6248f0f145a2047 (stream Message reader)
2017-12-16 07:28:40.592501 I | rafthttp: peer 6248f0f145a2047 became active
2017-12-16 07:28:40.593396 I | rafthttp: established a TCP streaming connection with peer 6248f0f145a2047 (stream Message writer)
2017-12-16 07:28:40.593565 I | rafthttp: established a TCP streaming connection with peer 6248f0f145a2047 (stream MsgApp v2 writer)
2017-12-16 07:28:40.605012 I | rafthttp: established a TCP streaming connection with peer 6248f0f145a2047 (stream Message reader)
2017-12-16 07:28:40.605340 I | rafthttp: established a TCP streaming connection with peer 6248f0f145a2047 (stream MsgApp v2 reader)
2017-12-16 07:28:41.249490 E | rafthttp: failed to write 6248f0f145a2047 on pipeline (dial tcp 160.10.2.31:11006: i/o timeout)
2017-12-16 07:28:41.249533 I | rafthttp: peer 6248f0f145a2047 became inactive
//other logs, but it don't change to active

I puzzle what condition can make a member be marked inactive, and why 6248f0f145a2047 did't change to active as first example.
And the etcd version is 3.1.0 .

@ghost
Copy link
Author

ghost commented Dec 20, 2017

I try to reproduce the situation with kinds of condition, but failed..........

@hexfusion
Copy link
Contributor

I try to reproduce the situation with kinds of condition, but failed..........

Hi @fallblank, do you mean you can not reproduce the issue or that you can? Can you please post the exact flags/ENV you are passing to etcd to start these nodes so we can try to reproduce?

@ghost
Copy link
Author

ghost commented Dec 20, 2017

I add members one by one to cluster though V2 Member api.

@ghost
Copy link
Author

ghost commented Dec 20, 2017

God! I reproduce it !!!
it seem a bug, I will attach all logs later.

@hexfusion
Copy link
Contributor

@fallblank nice work, have you tried against a more recent version of 3.1.x? The issue could be resolved. But yes please post logs.

@ghost
Copy link
Author

ghost commented Dec 21, 2017

Sorry for late. All logs below.
the leader node:
<-! TLS INFO IGNORE ->
2017-12-20 13:20:27.753578 I | etcdmain: etcd Version: 3.1.0
2017-12-20 13:20:27.753589 I | etcdmain: Git SHA: 8ba2897
2017-12-20 13:20:27.753594 I | etcdmain: Go Version: go1.7.4
2017-12-20 13:20:27.753598 I | etcdmain: Go OS/Arch: linux/amd64
2017-12-20 13:20:27.753605 I | etcdmain: setting maximum number of CPUs to 4, total number of available CPUs is 4
<-! TLS INFO IGNORE ->
2017-12-20 13:20:27.754851 I | embed: listening for peers on https://192.168.2.31:2380
2017-12-20 13:20:27.756989 I | embed: listening for peers on https://172.10.2.9:2380
2017-12-20 13:20:27.757058 I | embed: listening for client requests on 127.0.0.1:2379
2017-12-20 13:20:27.757100 I | embed: listening for client requests on 192.168.2.31:2379
2017-12-20 13:20:27.757171 I | embed: listening for client requests on 172.10.2.9:2379
2017-12-20 13:20:27.764818 I | warning: ignoring ServerName for user-provided CA for backwards compatibility is deprecated
2017-12-20 13:20:27.765176 I | pkg/netutil: resolving ETCD-172-10-2-9192-168-2-31-0.example.svc:2380 to 172.10.2.9:2380
2017-12-20 13:20:27.765239 I | pkg/netutil: resolving ETCD-172-10-2-9192-168-2-31-1.example.svc:2380 to 192.168.2.31:2380
2017-12-20 13:20:27.765306 I | pkg/netutil: resolving ETCD-172-10-2-9192-168-2-31-0.example.svc:2380 to 172.10.2.9:2380
2017-12-20 13:20:27.765341 I | pkg/netutil: resolving ETCD-172-10-2-9192-168-2-31-1.example.svc:2380 to 192.168.2.31:2380
2017-12-20 13:20:27.765416 I | etcdserver: name = ETCD-172-10-2-9192-168-2-31
2017-12-20 13:20:27.765423 I | etcdserver: data dir = ./data
2017-12-20 13:20:27.765429 I | etcdserver: member dir = ./data/member
2017-12-20 13:20:27.765433 I | etcdserver: heartbeat = 1000ms
2017-12-20 13:20:27.765438 I | etcdserver: election = 10000ms
2017-12-20 13:20:27.765443 I | etcdserver: snapshot count = 10000
2017-12-20 13:20:27.765456 I | etcdserver: advertise client URLs = https://ETCD-172-10-2-9192-168-2-31-0.example.svc:2379,https://ETCD-172-10-2-9192-168-2-31-1.example.svc:2379
2017-12-20 13:20:27.765466 I | etcdserver: initial advertise peer URLs = https://ETCD-172-10-2-9192-168-2-31-0.example.svc:2380,https://ETCD-172-10-2-9192-168-2-31-1.example.svc:2380
2017-12-20 13:20:27.765477 I | etcdserver: initial cluster = ETCD-172-10-2-9192-168-2-31=https://ETCD-172-10-2-9192-168-2-31-0.example.svc:2380,ETCD-172-10-2-9192-168-2-31=https://ETCD-172-10-2-9192-168-2-31-1.example.svc:2380
2017-12-20 13:20:27.770447 I | etcdserver: starting member e4ab1f961dc7b7ee in cluster fe85c15888eee52e
2017-12-20 13:20:27.770480 I | raft: e4ab1f961dc7b7ee became follower at term 0
2017-12-20 13:20:27.770496 I | raft: newRaft e4ab1f961dc7b7ee [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
2017-12-20 13:20:27.770508 I | raft: e4ab1f961dc7b7ee became follower at term 1
2017-12-20 13:20:27.787560 I | warning: ignoring ServerName for user-provided CA for backwards compatibility is deprecated
2017-12-20 13:20:27.788535 I | warning: ignoring ServerName for user-provided CA for backwards compatibility is deprecated
2017-12-20 13:20:27.788567 I | etcdserver: starting server... [version: 3.1.0, cluster version: to_be_decided]
<-! TLS INFO IGNORE ->
2017-12-20 13:20:27.789148 I | etcdserver/membership: added member e4ab1f961dc7b7ee [https://ETCD-172-10-2-9192-168-2-31-0.example.svc:2380 https://ETCD-172-10-2-9192-168-2-31-1.example.svc:2380] to cluster fe85c15888eee52e
2017-12-20 13:20:32.770847 I | raft: e4ab1f961dc7b7ee is starting a new election at term 1
2017-12-20 13:20:32.770894 I | raft: e4ab1f961dc7b7ee became candidate at term 2
2017-12-20 13:20:32.770918 I | raft: e4ab1f961dc7b7ee received MsgVoteResp from e4ab1f961dc7b7ee at term 2
2017-12-20 13:20:32.770935 I | raft: e4ab1f961dc7b7ee became leader at term 2
2017-12-20 13:20:32.770946 I | raft: raft.node: e4ab1f961dc7b7ee elected leader e4ab1f961dc7b7ee at term 2
2017-12-20 13:20:32.771246 I | etcdserver: setting up the initial cluster version to 3.1
2017-12-20 13:20:32.772405 N | etcdserver/membership: set the initial cluster version to 3.1
2017-12-20 13:20:32.772443 I | etcdserver/api: enabled capabilities for version 3.1
2017-12-20 13:20:32.772475 I | etcdserver: published {Name:ETCD-172-10-2-9192-168-2-31 ClientURLs:[https://ETCD-172-10-2-9192-168-2-31-0.example.svc:2379 https://ETCD-172-10-2-9192-168-2-31-1.example.svc:2379]} to cluster fe85c15888eee52e
2017-12-20 13:20:32.772588 I | embed: ready to serve client requests
2017-12-20 13:20:32.772643 I | embed: ready to serve client requests
2017-12-20 13:20:32.772954 I | embed: serving client requests on 192.168.2.31:2379
2017-12-20 13:20:32.772985 I | embed: serving client requests on 172.10.2.9:2379
2017-12-20 13:20:32.772996 I | embed: ready to serve client requests
2017-12-20 13:20:32.773196 I | embed: serving client requests on 127.0.0.1:2379
2017-12-20 13:20:32.775261 E | etcdmain: forgot to set Type=notify in systemd service file?
2017-12-20 13:22:17.848066 I | etcdserver/membership: added member 580f92ffca2eedb8 [https://ETCD-172-10-2-91192-168-2-3-0.example.svc:2380 https://ETCD-172-10-2-91192-168-2-3-1.example.svc:2380] to cluster fe85c15888eee52e
2017-12-20 13:22:17.848109 I | rafthttp: starting peer 580f92ffca2eedb8...
2017-12-20 13:22:17.848141 I | rafthttp: started HTTP pipelining with peer 580f92ffca2eedb8
2017-12-20 13:22:17.848450 I | rafthttp: started streaming with peer 580f92ffca2eedb8 (writer)
2017-12-20 13:22:17.848607 I | rafthttp: started streaming with peer 580f92ffca2eedb8 (writer)
2017-12-20 13:22:17.851749 I | rafthttp: started peer 580f92ffca2eedb8
2017-12-20 13:22:17.851774 I | rafthttp: started streaming with peer 580f92ffca2eedb8 (stream Message reader)
2017-12-20 13:22:17.851827 I | rafthttp: started streaming with peer 580f92ffca2eedb8 (stream MsgApp v2 reader)
2017-12-20 13:22:17.851916 I | rafthttp: added peer 580f92ffca2eedb8
2017-12-20 13:22:18.549642 I | rafthttp: peer 580f92ffca2eedb8 became active
2017-12-20 13:22:18.549677 I | rafthttp: established a TCP streaming connection with peer 580f92ffca2eedb8 (stream Message writer)
2017-12-20 13:22:18.553147 I | rafthttp: established a TCP streaming connection with peer 580f92ffca2eedb8 (stream Message reader)
2017-12-20 13:22:18.553541 I | rafthttp: established a TCP streaming connection with peer 580f92ffca2eedb8 (stream MsgApp v2 writer)
2017-12-20 13:22:18.555311 I | rafthttp: established a TCP streaming connection with peer 580f92ffca2eedb8 (stream MsgApp v2 reader)
2017-12-20 13:22:43.419926 I | etcdserver/membership: added member d45a805f009e718e [https://ETCD-172-10-9-168192-168-9-25-0.example.svc:2380 https://ETCD-172-10-9-168192-168-9-25-1.example.svc:2380] to cluster fe85c15888eee52e
2017-12-20 13:22:43.419994 I | rafthttp: starting peer d45a805f009e718e...
2017-12-20 13:22:43.420034 I | rafthttp: started HTTP pipelining with peer d45a805f009e718e
2017-12-20 13:22:43.420375 I | rafthttp: started streaming with peer d45a805f009e718e (writer)
2017-12-20 13:22:43.420531 I | rafthttp: started streaming with peer d45a805f009e718e (writer)
2017-12-20 13:22:43.420794 I | rafthttp: started peer d45a805f009e718e
2017-12-20 13:22:43.420818 I | rafthttp: started streaming with peer d45a805f009e718e (stream MsgApp v2 reader)
2017-12-20 13:22:43.420834 I | rafthttp: started streaming with peer d45a805f009e718e (stream Message reader)
2017-12-20 13:22:43.420927 I | rafthttp: added peer d45a805f009e718e
2017-12-20 13:22:44.064512 I | rafthttp: peer d45a805f009e718e became active
2017-12-20 13:22:44.064542 I | rafthttp: established a TCP streaming connection with peer d45a805f009e718e (stream MsgApp v2 writer)
2017-12-20 13:22:44.067126 I | rafthttp: established a TCP streaming connection with peer d45a805f009e718e (stream Message writer)
2017-12-20 13:22:46.521890 E | rafthttp: failed to dial d45a805f009e718e on stream Message (dial tcp 192.168.9.25:2380: i/o timeout)
2017-12-20 13:22:46.521923 I | rafthttp: peer d45a805f009e718e became inactive
2017-12-20 13:22:46.643009 I | rafthttp: peer d45a805f009e718e became active
2017-12-20 13:22:46.643038 I | rafthttp: established a TCP streaming connection with peer d45a805f009e718e (stream Message reader)
2017-12-20 13:22:46.644114 I | rafthttp: established a TCP streaming connection with peer d45a805f009e718e (stream MsgApp v2 reader)
2017-12-20 13:22:46.771089 E | rafthttp: failed to write d45a805f009e718e on pipeline (dial tcp 192.168.9.25:2380: i/o timeout)
2017-12-20 13:22:46.771121 I | rafthttp: peer d45a805f009e718e became inactive
2017-12-20 13:24:12.571998 W | etcdserver: not healthy for reconfigure, rejecting member add {ID:4b4d7d74684a21a RaftAttributes:{PeerURLs:[https://ETCD-172-10-9-18192-168-9-46-0.example.svc:2380 https://ETCD-172-10-9-18192-168-9-46-1.example.svc:2380]} Attributes:{Name: ClientURLs:[]}}
2017-12-20 13:24:12.572031 E | etcdserver/api/v2http: error adding member 4b4d7d74684a21a (etcdserver: unhealthy cluster)
2017-12-20 13:24:12.572046 E | etcdserver/api/v2http: etcdserver: unhealthy cluster
2017-12-20 13:24:22.658983 W | etcdserver: not healthy for reconfigure, rejecting member add {ID:90f1b576bc17c8c4 RaftAttributes:{PeerURLs:[https://ETCD-172-10-9-18192-168-9-46-0.example.svc:2380 https://ETCD-172-10-9-18192-168-9-46-1.example.svc:2380]} Attributes:{Name: ClientURLs:[]}}
2017-12-20 13:24:22.659015 E | etcdserver/api/v2http: error adding member 90f1b576bc17c8c4 (etcdserver: unhealthy cluster)
2017-12-20 13:24:22.659027 E | etcdserver/api/v2http: etcdserver: unhealthy cluster
2017-12-20 13:24:32.826242 W | etcdserver: not healthy for reconfigure, rejecting member add {ID:52d9e88eda0d80a4 RaftAttributes:{PeerURLs:[https://ETCD-172-10-9-18192-168-9-46-0.example.svc:2380 https://ETCD-172-10-9-18192-168-9-46-1.example.svc:2380]} Attributes:{Name: ClientURLs:[]}}
2017-12-20 13:24:32.826283 E | etcdserver/api/v2http: error adding member 52d9e88eda0d80a4 (etcdserver: unhealthy cluster)
2017-12-20 13:24:32.826295 E | etcdserver/api/v2http: etcdserver: unhealthy cluster

------dividing line ----------
follower node 1:
<-! TLS INFO IGNORE ->
2017-12-20 13:22:17.736230 I | etcdmain: etcd Version: 3.1.0
2017-12-20 13:22:17.736240 I | etcdmain: Git SHA: 8ba2897
2017-12-20 13:22:17.736245 I | etcdmain: Go Version: go1.7.4
2017-12-20 13:22:17.736249 I | etcdmain: Go OS/Arch: linux/amd64
2017-12-20 13:22:17.736256 I | etcdmain: setting maximum number of CPUs to 4, total number of available CPUs is 4
<-! TLS INFO IGNORE ->
2017-12-20 13:22:17.737743 I | embed: listening for peers on https://192.168.2.3:2380
2017-12-20 13:22:17.741519 I | embed: listening for peers on https://172.10.2.91:2380
2017-12-20 13:22:17.741661 I | embed: listening for client requests on 127.0.0.1:2379
2017-12-20 13:22:17.741749 I | embed: listening for client requests on 192.168.2.3:2379
2017-12-20 13:22:17.741896 I | embed: listening for client requests on 172.10.2.91:2379
2017-12-20 13:22:17.760754 I | warning: ignoring ServerName for user-provided CA for backwards compatibility is deprecated
2017-12-20 13:22:17.801245 I | pkg/netutil: resolving ETCD-172-10-2-91192-168-2-3-0.example.svc:2380 to 172.10.2.91:2380
2017-12-20 13:22:17.801343 I | pkg/netutil: resolving ETCD-172-10-2-91192-168-2-3-1.example.svc:2380 to 192.168.2.3:2380
2017-12-20 13:22:17.801422 I | pkg/netutil: resolving ETCD-172-10-2-91192-168-2-3-0.example.svc:2380 to 172.10.2.91:2380
2017-12-20 13:22:17.801480 I | pkg/netutil: resolving ETCD-172-10-2-91192-168-2-3-1.example.svc:2380 to 192.168.2.3:2380
2017-12-20 13:22:17.801577 I | pkg/netutil: resolving ETCD-172-10-2-9192-168-2-31-0.example.svc:2380 to 172.10.2.9:2380
2017-12-20 13:22:17.801631 I | pkg/netutil: resolving ETCD-172-10-2-9192-168-2-31-1.example.svc:2380 to 192.168.2.31:2380
2017-12-20 13:22:17.801695 I | pkg/netutil: resolving ETCD-172-10-2-9192-168-2-31-0.example.svc:2380 to 172.10.2.9:2380
2017-12-20 13:22:17.801737 I | pkg/netutil: resolving ETCD-172-10-2-9192-168-2-31-1.example.svc:2380 to 192.168.2.31:2380
2017-12-20 13:22:17.802381 I | etcdserver: name = ETCD-172-10-2-91192-168-2-3
2017-12-20 13:22:17.802408 I | etcdserver: data dir = ./data
2017-12-20 13:22:17.802420 I | etcdserver: member dir = ./data/member
2017-12-20 13:22:17.802428 I | etcdserver: heartbeat = 1000ms
2017-12-20 13:22:17.802436 I | etcdserver: election = 10000ms
2017-12-20 13:22:17.802444 I | etcdserver: snapshot count = 10000
2017-12-20 13:22:17.802468 I | etcdserver: advertise client URLs = https://ETCD-172-10-2-91192-168-2-3-0.example.svc:2379,https://ETCD-172-10-2-91192-168-2-3-1.example.svc:2379
2017-12-20 13:22:17.814267 I | etcdserver: starting member 580f92ffca2eedb8 in cluster fe85c15888eee52e
2017-12-20 13:22:17.814334 I | raft: 580f92ffca2eedb8 became follower at term 0
2017-12-20 13:22:17.814365 I | raft: newRaft 580f92ffca2eedb8 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
2017-12-20 13:22:17.814372 I | raft: 580f92ffca2eedb8 became follower at term 1
2017-12-20 13:22:17.845365 I | warning: ignoring ServerName for user-provided CA for backwards compatibility is deprecated
2017-12-20 13:22:17.847295 I | warning: ignoring ServerName for user-provided CA for backwards compatibility is deprecated
2017-12-20 13:22:17.847440 I | rafthttp: started HTTP pipelining with peer e4ab1f961dc7b7ee
2017-12-20 13:22:17.847485 I | rafthttp: starting peer e4ab1f961dc7b7ee...
2017-12-20 13:22:17.847511 I | rafthttp: started HTTP pipelining with peer e4ab1f961dc7b7ee
2017-12-20 13:22:17.850116 I | rafthttp: started streaming with peer e4ab1f961dc7b7ee (writer)
2017-12-20 13:22:17.850603 I | rafthttp: started streaming with peer e4ab1f961dc7b7ee (writer)
2017-12-20 13:22:17.853315 I | rafthttp: started peer e4ab1f961dc7b7ee
2017-12-20 13:22:17.853374 I | rafthttp: added peer e4ab1f961dc7b7ee
2017-12-20 13:22:17.853401 I | etcdserver: starting server... [version: 3.1.0, cluster version: to_be_decided]
<-! TLS INFO IGNORE ->
2017-12-20 13:22:17.854174 I | rafthttp: started streaming with peer e4ab1f961dc7b7ee (stream MsgApp v2 reader)
2017-12-20 13:22:17.854647 I | rafthttp: started streaming with peer e4ab1f961dc7b7ee (stream Message reader)
2017-12-20 13:22:17.871255 I | rafthttp: peer e4ab1f961dc7b7ee became active
2017-12-20 13:22:17.871302 I | rafthttp: established a TCP streaming connection with peer e4ab1f961dc7b7ee (stream Message reader)
2017-12-20 13:22:17.874472 I | rafthttp: established a TCP streaming connection with peer e4ab1f961dc7b7ee (stream Message writer)
2017-12-20 13:22:17.875201 I | rafthttp: established a TCP streaming connection with peer e4ab1f961dc7b7ee (stream MsgApp v2 reader)
2017-12-20 13:22:17.877101 I | rafthttp: established a TCP streaming connection with peer e4ab1f961dc7b7ee (stream MsgApp v2 writer)
2017-12-20 13:22:18.095793 I | raft: 580f92ffca2eedb8 [term: 1] received a MsgHeartbeat message with higher term from e4ab1f961dc7b7ee [term: 2]
2017-12-20 13:22:18.095839 I | raft: 580f92ffca2eedb8 became follower at term 2
2017-12-20 13:22:18.095860 I | raft: raft.node: 580f92ffca2eedb8 elected leader e4ab1f961dc7b7ee at term 2
2017-12-20 13:22:18.099394 I | etcdserver/membership: added member e4ab1f961dc7b7ee [https://ETCD-172-10-2-9192-168-2-31-0.example.svc:2380 https://ETCD-172-10-2-9192-168-2-31-1.example.svc:2380] to cluster fe85c15888eee52e
2017-12-20 13:22:18.099598 N | etcdserver/membership: set the initial cluster version to 3.1
2017-12-20 13:22:18.099653 I | etcdserver/api: enabled capabilities for version 3.1
2017-12-20 13:22:18.099820 I | etcdserver/membership: added member 580f92ffca2eedb8 [https://ETCD-172-10-2-91192-168-2-3-0.example.svc:2380 https://ETCD-172-10-2-91192-168-2-3-1.example.svc:2380] to cluster fe85c15888eee52e
2017-12-20 13:22:18.101712 I | etcdserver: published {Name:ETCD-172-10-2-91192-168-2-3 ClientURLs:[https://ETCD-172-10-2-91192-168-2-3-0.example.svc:2379 https://ETCD-172-10-2-91192-168-2-3-1.example.svc:2379]} to cluster fe85c15888eee52e
2017-12-20 13:22:18.101792 I | embed: ready to serve client requests
2017-12-20 13:22:18.101831 I | embed: ready to serve client requests
2017-12-20 13:22:18.102241 I | embed: serving client requests on 127.0.0.1:2379
2017-12-20 13:22:18.102284 I | embed: serving client requests on 192.168.2.3:2379
2017-12-20 13:22:18.103266 E | etcdmain: forgot to set Type=notify in systemd service file?
2017-12-20 13:22:18.104316 I | embed: ready to serve client requests
2017-12-20 13:22:18.104661 I | embed: serving client requests on 172.10.2.91:2379
2017-12-20 13:22:42.741465 I | etcdserver/membership: added member d45a805f009e718e [https://ETCD-172-10-9-168192-168-9-25-0.example.svc:2380 https://ETCD-172-10-9-168192-168-9-25-1.example.svc:2380] to cluster fe85c15888eee52e
2017-12-20 13:22:42.741543 I | rafthttp: starting peer d45a805f009e718e...
2017-12-20 13:22:42.741587 I | rafthttp: started HTTP pipelining with peer d45a805f009e718e
2017-12-20 13:22:42.742486 I | rafthttp: started peer d45a805f009e718e
2017-12-20 13:22:42.742519 I | rafthttp: added peer d45a805f009e718e
2017-12-20 13:22:42.742654 I | rafthttp: started streaming with peer d45a805f009e718e (writer)
2017-12-20 13:22:42.742678 I | rafthttp: started streaming with peer d45a805f009e718e (writer)
2017-12-20 13:22:42.742728 I | rafthttp: started streaming with peer d45a805f009e718e (stream MsgApp v2 reader)
2017-12-20 13:22:42.743096 I | rafthttp: started streaming with peer d45a805f009e718e (stream Message reader)
2017-12-20 13:22:43.384987 I | rafthttp: peer d45a805f009e718e became active
2017-12-20 13:22:43.385026 I | rafthttp: established a TCP streaming connection with peer d45a805f009e718e (stream Message writer)
2017-12-20 13:22:43.387296 I | rafthttp: established a TCP streaming connection with peer d45a805f009e718e (stream MsgApp v2 writer)
2017-12-20 13:22:45.843983 E | rafthttp: failed to dial d45a805f009e718e on stream MsgApp v2 (dial tcp 192.168.9.25:2380: i/o timeout)
2017-12-20 13:22:45.844045 I | rafthttp: peer d45a805f009e718e became inactive
2017-12-20 13:22:45.959883 I | rafthttp: peer d45a805f009e718e became active
2017-12-20 13:22:45.959934 I | rafthttp: established a TCP streaming connection with peer d45a805f009e718e (stream MsgApp v2 reader)
2017-12-20 13:22:45.966790 I | rafthttp: established a TCP streaming connection with peer d45a805f009e718e (stream Message reader)
2017-12-20 13:38:48.312853 W | rafthttp: the clock difference against peer d45a805f009e718e is too high [1.093755938s > 1s]
2017-12-20 13:39:18.313178 W | rafthttp: the clock difference against peer d45a805f009e718e is too high [1.093684526s > 1s]
2017-12-20 13:39:48.435498 W | rafthttp: the clock difference against peer d45a805f009e718e is too high [1.215525866s > 1s]

------dividing line ----------
follower node 2:
<-! TLS INFO IGNORE ->
2017-12-20 13:22:43.192239 I | etcdmain: etcd Version: 3.1.0
2017-12-20 13:22:43.192248 I | etcdmain: Git SHA: 8ba2897
2017-12-20 13:22:43.192253 I | etcdmain: Go Version: go1.7.4
2017-12-20 13:22:43.192259 I | etcdmain: Go OS/Arch: linux/amd64
2017-12-20 13:22:43.192266 I | etcdmain: setting maximum number of CPUs to 4, total number of available CPUs is 4
<-! TLS INFO IGNORE ->
2017-12-20 13:22:43.194168 I | embed: listening for peers on https://192.168.9.25:2380
2017-12-20 13:22:43.196294 I | embed: listening for peers on https://172.10.9.168:2380
2017-12-20 13:22:43.196383 I | embed: listening for client requests on 127.0.0.1:2379
2017-12-20 13:22:43.196450 I | embed: listening for client requests on 192.168.9.25:2379
2017-12-20 13:22:43.196567 I | embed: listening for client requests on 172.10.9.168:2379
2017-12-20 13:22:43.204370 I | warning: ignoring ServerName for user-provided CA for backwards compatibility is deprecated
2017-12-20 13:22:43.240976 I | pkg/netutil: resolving ETCD-172-10-2-91192-168-2-3-0.example.svc:2380 to 172.10.2.91:2380
2017-12-20 13:22:43.241070 I | pkg/netutil: resolving ETCD-172-10-2-91192-168-2-3-1.example.svc:2380 to 192.168.2.3:2380
2017-12-20 13:22:43.241115 I | pkg/netutil: resolving ETCD-172-10-2-91192-168-2-3-0.example.svc:2380 to 172.10.2.91:2380
2017-12-20 13:22:43.241148 I | pkg/netutil: resolving ETCD-172-10-2-91192-168-2-3-1.example.svc:2380 to 192.168.2.3:2380
2017-12-20 13:22:43.241245 I | pkg/netutil: resolving ETCD-172-10-2-9192-168-2-31-0.example.svc:2380 to 172.10.2.9:2380
2017-12-20 13:22:43.241280 I | pkg/netutil: resolving ETCD-172-10-2-9192-168-2-31-1.example.svc:2380 to 192.168.2.31:2380
2017-12-20 13:22:43.241327 I | pkg/netutil: resolving ETCD-172-10-2-9192-168-2-31-0.example.svc:2380 to 172.10.2.9:2380
2017-12-20 13:22:43.241357 I | pkg/netutil: resolving ETCD-172-10-2-9192-168-2-31-1.example.svc:2380 to 192.168.2.31:2380
2017-12-20 13:22:43.241419 I | pkg/netutil: resolving ETCD-172-10-9-168192-168-9-25-0.example.svc:2380 to 172.10.9.168:2380
2017-12-20 13:22:43.241450 I | pkg/netutil: resolving ETCD-172-10-9-168192-168-9-25-1.example.svc:2380 to 192.168.9.25:2380
2017-12-20 13:22:43.241507 I | pkg/netutil: resolving ETCD-172-10-9-168192-168-9-25-0.example.svc:2380 to 172.10.9.168:2380
2017-12-20 13:22:43.241535 I | pkg/netutil: resolving ETCD-172-10-9-168192-168-9-25-1.example.svc:2380 to 192.168.9.25:2380
2017-12-20 13:22:43.257999 I | etcdserver: name = ETCD-172-10-9-168192-168-9-25
2017-12-20 13:22:43.258044 I | etcdserver: data dir = ./data
2017-12-20 13:22:43.258056 I | etcdserver: member dir = ./data/member
2017-12-20 13:22:43.258065 I | etcdserver: heartbeat = 1000ms
2017-12-20 13:22:43.258078 I | etcdserver: election = 10000ms
2017-12-20 13:22:43.258086 I | etcdserver: snapshot count = 10000
2017-12-20 13:22:43.258116 I | etcdserver: advertise client URLs = https://ETCD-172-10-9-168192-168-9-25-0.example.svc:2379,https://ETCD-172-10-9-168192-168-9-25-1.example.svc:2379
2017-12-20 13:22:43.264228 I | etcdserver: starting member d45a805f009e718e in cluster fe85c15888eee52e
2017-12-20 13:22:43.264293 I | raft: d45a805f009e718e became follower at term 0
2017-12-20 13:22:43.264319 I | raft: newRaft d45a805f009e718e [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
2017-12-20 13:22:43.264331 I | raft: d45a805f009e718e became follower at term 1
2017-12-20 13:22:43.351455 I | warning: ignoring ServerName for user-provided CA for backwards compatibility is deprecated
2017-12-20 13:22:43.352462 I | warning: ignoring ServerName for user-provided CA for backwards compatibility is deprecated
2017-12-20 13:22:43.352543 I | rafthttp: started HTTP pipelining with peer 580f92ffca2eedb8
2017-12-20 13:22:43.352697 I | rafthttp: started HTTP pipelining with peer e4ab1f961dc7b7ee
2017-12-20 13:22:43.352745 I | rafthttp: starting peer 580f92ffca2eedb8...
2017-12-20 13:22:43.352851 I | rafthttp: started HTTP pipelining with peer 580f92ffca2eedb8
2017-12-20 13:22:43.354678 I | rafthttp: started streaming with peer 580f92ffca2eedb8 (writer)
2017-12-20 13:22:43.358528 I | rafthttp: started peer 580f92ffca2eedb8
2017-12-20 13:22:43.358601 I | rafthttp: added peer 580f92ffca2eedb8
2017-12-20 13:22:43.358656 I | rafthttp: starting peer e4ab1f961dc7b7ee...
2017-12-20 13:22:43.358690 I | rafthttp: started HTTP pipelining with peer e4ab1f961dc7b7ee
2017-12-20 13:22:43.358936 I | rafthttp: started streaming with peer 580f92ffca2eedb8 (writer)
2017-12-20 13:22:43.358994 I | rafthttp: started streaming with peer 580f92ffca2eedb8 (stream MsgApp v2 reader)
2017-12-20 13:22:43.359875 I | rafthttp: started streaming with peer e4ab1f961dc7b7ee (writer)
2017-12-20 13:22:43.360078 I | rafthttp: started streaming with peer e4ab1f961dc7b7ee (writer)
2017-12-20 13:22:43.360540 I | rafthttp: started streaming with peer 580f92ffca2eedb8 (stream Message reader)
2017-12-20 13:22:43.361335 I | rafthttp: started peer e4ab1f961dc7b7ee
2017-12-20 13:22:43.361366 I | rafthttp: added peer e4ab1f961dc7b7ee
2017-12-20 13:22:43.361384 I | rafthttp: started streaming with peer e4ab1f961dc7b7ee (stream Message reader)
2017-12-20 13:22:43.361481 I | etcdserver: starting server... [version: 3.1.0, cluster version: to_be_decided]
<-! TLS INFO IGNORE ->
2017-12-20 13:22:43.361695 I | rafthttp: started streaming with peer e4ab1f961dc7b7ee (stream MsgApp v2 reader)
2017-12-20 13:22:43.377167 I | rafthttp: peer 580f92ffca2eedb8 became active
2017-12-20 13:22:43.377226 I | rafthttp: established a TCP streaming connection with peer 580f92ffca2eedb8 (stream Message reader)
2017-12-20 13:22:43.377816 I | rafthttp: peer e4ab1f961dc7b7ee became active
2017-12-20 13:22:43.377836 I | rafthttp: established a TCP streaming connection with peer e4ab1f961dc7b7ee (stream MsgApp v2 reader)
2017-12-20 13:22:43.379363 I | rafthttp: established a TCP streaming connection with peer 580f92ffca2eedb8 (stream MsgApp v2 reader)
2017-12-20 13:22:43.380480 I | rafthttp: established a TCP streaming connection with peer e4ab1f961dc7b7ee (stream Message reader)
2017-12-20 13:22:44.084787 I | raft: d45a805f009e718e [term: 1] received a MsgHeartbeat message with higher term from e4ab1f961dc7b7ee [term: 2]
2017-12-20 13:22:44.084838 I | raft: d45a805f009e718e became follower at term 2
2017-12-20 13:22:44.084856 I | raft: raft.node: d45a805f009e718e elected leader e4ab1f961dc7b7ee at term 2
2017-12-20 13:22:44.106075 I | etcdserver/membership: added member e4ab1f961dc7b7ee [https://ETCD-172-10-2-9192-168-2-31-0.example.svc:2380 https://ETCD-172-10-2-9192-168-2-31-1.example.svc:2380] to cluster fe85c15888eee52e
2017-12-20 13:22:44.106220 N | etcdserver/membership: set the initial cluster version to 3.1
2017-12-20 13:22:44.106255 I | etcdserver/api: enabled capabilities for version 3.1
2017-12-20 13:22:44.106348 I | etcdserver/membership: added member 580f92ffca2eedb8 [https://ETCD-172-10-2-91192-168-2-3-0.example.svc:2380 https://ETCD-172-10-2-91192-168-2-3-1.example.svc:2380] to cluster fe85c15888eee52e
2017-12-20 13:22:44.106488 I | etcdserver/membership: added member d45a805f009e718e [https://ETCD-172-10-9-168192-168-9-25-0.example.svc:2380 https://ETCD-172-10-9-168192-168-9-25-1.example.svc:2380] to cluster fe85c15888eee52e
2017-12-20 13:22:44.107896 I | etcdserver: published {Name:ETCD-172-10-9-168192-168-9-25 ClientURLs:[https://ETCD-172-10-9-168192-168-9-25-0.example.svc:2379 https://ETCD-172-10-9-168192-168-9-25-1.example.svc:2379]} to cluster fe85c15888eee52e
2017-12-20 13:22:44.107969 E | etcdmain: forgot to set Type=notify in systemd service file?
2017-12-20 13:22:44.108486 I | embed: ready to serve client requests
2017-12-20 13:22:44.108695 I | embed: serving client requests on 192.168.9.25:2379
2017-12-20 13:22:44.108745 I | embed: ready to serve client requests
2017-12-20 13:22:44.108968 I | embed: serving client requests on 127.0.0.1:2379
2017-12-20 13:22:44.109003 I | embed: ready to serve client requests
2017-12-20 13:22:44.109241 I | embed: serving client requests on 172.10.9.168:2379
2017-12-20 13:22:45.955061 I | rafthttp: established a TCP streaming connection with peer 580f92ffca2eedb8 (stream MsgApp v2 writer)
2017-12-20 13:22:45.956116 I | rafthttp: established a TCP streaming connection with peer e4ab1f961dc7b7ee (stream Message writer)
2017-12-20 13:22:45.957567 I | rafthttp: established a TCP streaming connection with peer e4ab1f961dc7b7ee (stream MsgApp v2 writer)
2017-12-20 13:22:45.958415 I | rafthttp: established a TCP streaming connection with peer 580f92ffca2eedb8 (stream Message writer)
2017-12-20 14:25:27.034994 I | mvcc: store.index: compact 1
2017-12-20 14:25:27.035139 I | mvcc: finished scheduled compaction at 1 (took 46.541µs)

@ghost
Copy link
Author

ghost commented Dec 21, 2017

when I run etcdctl cluster-health command, it return:

member 580f92ffca2eedb8 is healthy: got healthy result from https://ETCD-172-10-2-91192-168-2-3-0.example.svc:2379
member d45a805f009e718e is healthy: got healthy result from https://ETCD-172-10-9-168192-168-9-25-0.example.svc:2379
member e4ab1f961dc7b7ee is healthy: got healthy result from https://ETCD-172-10-2-9192-168-2-31-0.example.svc:2379
cluster is healthy

@ghost
Copy link
Author

ghost commented Dec 21, 2017

but on the leader node, it print unhealthy cluster when I try to add a new node to cluster

@ghost
Copy link
Author

ghost commented Dec 21, 2017

After I restart leader node process, all thing goes well, the new node can be add normally.

@ghost
Copy link
Author

ghost commented Dec 21, 2017

@hexfusion

The issue could be resolved.

Is there a link for relative release note?

@hexfusion
Copy link
Contributor

hexfusion commented Dec 21, 2017

Is there a link for relative release note?

@fallblank Just a general comment, thanks for the logs I hope to review soon. In the meantime try to replicate against latest? v3.1.11 ?

@gyuho
Copy link
Contributor

gyuho commented Dec 21, 2017

Duplicate with #8383. Should be fixed in v3.3.

Please try https://github.com/coreos/etcd/releases/tag/v3.3.0-rc.0 and reopen if the problem still remains.

@gyuho gyuho closed this as completed Dec 21, 2017
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

No branches or pull requests

2 participants