Skip to content
This repository has been archived by the owner on May 24, 2020. It is now read-only.

One of the etcd container got deleted automatically, two of the etcd container status went to completed state #15

Closed
rmadaka opened this issue Oct 8, 2018 · 53 comments
Assignees
Labels
GCS/0.5 GCS 0.5 release

Comments

@rmadaka
Copy link

rmadaka commented Oct 8, 2018

  1. Create two pvcs, mounted one pvc to app pod.
  2. Ran I/O's on app pod
  3. Then delete the volume from GD2 container, volume deleted successfully
  4. Then try delete the pvc from kubernetes master node.
  5. PVC status went to terminating state.
  6. Then deleted the app pod where pvc is mounted.
  7. Afterwards PVC deleted successfully.
  8. Next day when i logged in to setup. Setup went to below state.
NAME                                   READY     STATUS             RESTARTS   AGE
csi-attacher-glusterfsplugin-0         2/2       Running            0          1d
csi-nodeplugin-glusterfsplugin-6lmb5   2/2       Running            0          1d
csi-nodeplugin-glusterfsplugin-sjgjb   2/2       Running            0          1d
csi-nodeplugin-glusterfsplugin-t6vhd   2/2       Running            0          1d
csi-provisioner-glusterfsplugin-0      2/2       Running            0          1d
etcd-hp5qsghwnk                        0/1       Completed          0          1d
etcd-operator-989bf8569-d9fpt          1/1       Running            1          1d
etcd-rz76vs6p77                        0/1       Completed          0          1d
glusterd2-cluster-px8qh                0/1       CrashLoopBackOff   219        1d
glusterd2-cluster-sq2q7                0/1       CrashLoopBackOff   219        1d
glusterd2-cluster-wqj4l                1/1       Running            218        1d
  1. It seems like one of the etcd container deleted, i am able to see only two etcd ocntainers which are in "completed state" and one etcd operator container which is in running sate.

  2. GD2 containers keep on restarting. i think this because of etcd. Able to see below errors from glusted2.log

time="2018-10-05 14:03:20.249447" level=warning msg="could not read store config file, continuing with defaults" error="open /var/lib/glusterd2/store.toml: no such file or directory" source="[config.go:128:store.GetConfig]"
time="2018-10-05 14:03:25.250568" level=error msg="failed to start embedded store" error="context deadline exceeded" source="[embed.go:36:store.newEmbedStore]"
time="2018-10-05 14:03:25.250669" level=fatal msg="Failed to initialize store (etcd client)" error="context deadline exceeded" source="[main.go:101:main.main]"
~

@rmadaka
Copy link
Author

rmadaka commented Oct 8, 2018

I am able to repro this issue. Second time what i have tried, providing steps below.

  1. Create two pvcs, mounted two pvcs to 3 replica controller app pods.
  2. Then ran I/O's on both the mount points.
  3. Then deleted both the volume from GD2 container, volumes deleted successfully
  4. Then try delete both the pvc from kubernetes master node.
  5. PVCS status went to terminating state.
  6. Then deleted the all replica controller app pods where pvcs are mounted.
  7. Afterwards PVC deleted successfully.
  8. All etcd containers went to completed state. Afterwards not able to create PVC itself.

Setup went to below state

NAME                                   READY     STATUS      RESTARTS   AGE
csi-attacher-glusterfsplugin-0         2/2       Running     0          4d
csi-nodeplugin-glusterfsplugin-brdn8   2/2       Running     0          4d
csi-nodeplugin-glusterfsplugin-fx6f9   2/2       Running     0          4d
csi-nodeplugin-glusterfsplugin-xr5fn   2/2       Running     0          4d
csi-provisioner-glusterfsplugin-0      2/2       Running     0          4d
etcd-h6hrvvzh5r                        0/1       Completed   0          26m
etcd-operator-989bf8569-r62s6          1/1       Running     0          4d
etcd-qkqtqnsqxr                        0/1       Completed   0          4d
etcd-r5dwf56bqn                        0/1       Completed   0          4d
glusterd2-cluster-6mvbd                1/1       Running     5          4d
glusterd2-cluster-gcdk6                1/1       Running     5          4d
glusterd2-cluster-q7g6b                1/1       Running     6          4d

@rmadaka
Copy link
Author

rmadaka commented Oct 10, 2018

With latest repo, created one pvc then i have rebooted one of the gd2 pod. Two of the etcd container status went to completed state.

Then logged in to GD2 pod , tried to perform glustercli commands, GD2 pods went to hung state.
Now I am not able to use this setup. It seems like serious issue.

NAME                                   READY   STATUS      RESTARTS   AGE
csi-attacher-glusterfsplugin-0         2/2     Running     0          18h
csi-nodeplugin-glusterfsplugin-2twn9   2/2     Running     0          18h
csi-nodeplugin-glusterfsplugin-dc6zr   2/2     Running     0          18h
csi-nodeplugin-glusterfsplugin-rcb72   2/2     Running     0          18h
csi-provisioner-glusterfsplugin-0      2/2     Running     0          18h
etcd-hgkcl46ldg                        0/1     Completed   0          18h
etcd-operator-7cb5bd459b-6jbvr         1/1     Running     0          18h
etcd-pfj48x67nd                        1/1     Running     0          18h
etcd-r7cffdlxqs                        0/1     Completed   0          18h
kube1-0                                1/1     Running     12         18h
kube2-0                                1/1     Running     1          18h
kube3-0                                1/1     Running     0          18h

@ksandha
Copy link

ksandha commented Oct 10, 2018

I faced the same issue. my pods got in crashLooopbackoff mode

[vagrant@kube1 ~]$ kubectl get pods -n gcs
NAME                                   READY   STATUS             RESTARTS   AGE
csi-attacher-glusterfsplugin-0         2/2     Running            0          19h
csi-nodeplugin-glusterfsplugin-m4xhq   2/2     Running            0          19h
csi-nodeplugin-glusterfsplugin-mjvlf   2/2     Running            0          19h
csi-nodeplugin-glusterfsplugin-n5spr   2/2     Running            0          19h
csi-provisioner-glusterfsplugin-0      2/2     Running            0          19h
etcd-8754rsgm2l                        0/1     Completed          0          19h
etcd-operator-7cb5bd459b-kjjzj         1/1     Running            1          19h
etcd-xhgv57q8tq                        0/1     Completed          0          19h
kube1-0                                0/1     CrashLoopBackOff   31         156m
kube2-0                                1/1     Running            0          19h
kube3-0                                1/1     Running            0          19h
[vagrant@kube1 ~]$ 

@Madhu-1
Copy link
Member

Madhu-1 commented Oct 10, 2018

logs from etcd container

2018-10-10 07:03:00.526710 I | raft: 6662ba3ec5887a79 [logterm: 99, index: 200] sent MsgVote request to 65f10b198e9973df at term 142
2018-10-10 07:03:00.526733 I | raft: 6662ba3ec5887a79 [logterm: 99, index: 200] sent MsgVote request to 187e5e3857382658 at term 142
2018-10-10 07:03:02.226507 I | raft: 6662ba3ec5887a79 is starting a new election at term 142
2018-10-10 07:03:02.226549 I | raft: 6662ba3ec5887a79 became candidate at term 143
2018-10-10 07:03:02.226562 I | raft: 6662ba3ec5887a79 received MsgVoteResp from 6662ba3ec5887a79 at term 143
2018-10-10 07:03:02.226574 I | raft: 6662ba3ec5887a79 [logterm: 99, index: 200] sent MsgVote request to 187e5e3857382658 at term 143
2018-10-10 07:03:02.226585 I | raft: 6662ba3ec5887a79 [logterm: 99, index: 200] sent MsgVote request to 7b8c323b5f7eb90d at term 143
2018-10-10 07:03:02.226596 I | raft: 6662ba3ec5887a79 [logterm: 99, index: 200] sent MsgVote request to 65f10b198e9973df at term 143
2018-10-10 07:03:02.721562 W | rafthttp: health check for peer 7b8c323b5f7eb90d could not connect: dial tcp [fe80::f8bf:e9ff:feca:2205]:2380: connect: invalid argument
2018-10-10 07:03:03.289662 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context deadline exceeded" took too long (4.998687126s) to execute
2018-10-10 07:03:03.297251 N | pkg/osutil: received terminated signal, shutting down...
2018-10-10 07:03:03.297690 I | etcdserver: skipped leadership transfer for stopping non-leader member
2018-10-10 07:03:03.298061 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context canceled" took too long (3.026999408s) to execute
WARNING: 2018/10/10 07:03:03 grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"
2018-10-10 07:03:03.298172 I | rafthttp: stopping peer 65f10b198e9973df...
2018-10-10 07:03:03.298530 I | rafthttp: closed the TCP streaming connection with peer 65f10b198e9973df (stream MsgApp v2 writer)
2018-10-10 07:03:03.298541 I | rafthttp: stopped streaming with peer 65f10b198e9973df (writer)
2018-10-10 07:03:03.299076 I | rafthttp: closed the TCP streaming connection with peer 65f10b198e9973df (stream Message writer)
2018-10-10 07:03:03.299088 I | rafthttp: stopped streaming with peer 65f10b198e9973df (writer)
2018-10-10 07:03:03.299166 I | rafthttp: stopped HTTP pipelining with peer 65f10b198e9973df
2018-10-10 07:03:03.299189 I | rafthttp: stopped streaming with peer 65f10b198e9973df (stream MsgApp v2 reader)
2018-10-10 07:03:03.299203 I | rafthttp: stopped streaming with peer 65f10b198e9973df (stream Message reader)
2018-10-10 07:03:03.299211 I | rafthttp: stopped peer 65f10b198e9973df
2018-10-10 07:03:03.299217 I | rafthttp: stopping peer 187e5e3857382658...
2018-10-10 07:03:03.299550 I | rafthttp: closed the TCP streaming connection with peer 187e5e3857382658 (stream MsgApp v2 writer)
2018-10-10 07:03:03.299560 I | rafthttp: stopped streaming with peer 187e5e3857382658 (writer)
2018-10-10 07:03:03.299880 I | rafthttp: closed the TCP streaming connection with peer 187e5e3857382658 (stream Message writer)
2018-10-10 07:03:03.299890 I | rafthttp: stopped streaming with peer 187e5e3857382658 (writer)
2018-10-10 07:03:03.299995 I | rafthttp: stopped HTTP pipelining with peer 187e5e3857382658
2018-10-10 07:03:03.300021 I | rafthttp: stopped streaming with peer 187e5e3857382658 (stream MsgApp v2 reader)
2018-10-10 07:03:03.300041 I | rafthttp: stopped streaming with peer 187e5e3857382658 (stream Message reader)
2018-10-10 07:03:03.300049 I | rafthttp: stopped peer 187e5e3857382658
2018-10-10 07:03:03.300055 I | rafthttp: stopping peer 7b8c323b5f7eb90d...
2018-10-10 07:03:03.300064 I | rafthttp: stopped streaming with peer 7b8c323b5f7eb90d (writer)
2018-10-10 07:03:03.300073 I | rafthttp: stopped streaming with peer 7b8c323b5f7eb90d (writer)
2018-10-10 07:03:03.300190 I | rafthttp: stopped HTTP pipelining with peer 7b8c323b5f7eb90d
2018-10-10 07:03:03.300206 I | rafthttp: stopped streaming with peer 7b8c323b5f7eb90d (stream MsgApp v2 reader)
2018-10-10 07:03:03.300217 I | rafthttp: stopped streaming with peer 7b8c323b5f7eb90d (stream Message reader)
2018-10-10 07:03:03.300223 I | rafthttp: stopped peer 7b8c323b5f7eb90d

@Madhu-1
Copy link
Member

Madhu-1 commented Oct 10, 2018

as ETCD containers are going down we are facing issue in glusterd2 containers
log from glusterd2 container

time="2018-10-10 10:02:46.572128" level=error msg="failed to start embedded store" error="dial tcp 10.233.17.123:2379: getsockopt: no route to host" source="[embed.go:36:store.newEmbedStore]"
time="2018-10-10 10:02:46.572264" level=fatal msg="Failed to initialize store (etcd client)" error="dial tcp 10.233.17.123:2379: getsockopt: no route to host" source="[main.go:101:main.main]"
time="2018-10-10 10:05:41.418800" level=info msg="loaded configuration from file" file=/etc/glusterd2/glusterd2.toml source="[config.go:109:main.dumpConfigToLog]"
time="2018-10-10 10:05:41.431963" level=info msg="Registered validation function for xlator" source="[load.go:140:xlator.loadXlator]" xlator=afr
time="2018-10-10 10:05:41.433568" level=info msg="Registered validation function for xlator" source="[load.go:140:xlator.loadXlator]" xlator=dht
time="2018-10-10 10:05:41.435664" level=info msg="Registered validation function for xlator" source="[load.go:140:xlator.loadXlator]" xlator=distribute
time="2018-10-10 10:05:41.438731" level=info msg="Registered validation function for xlator" source="[load.go:140:xlator.loadXlator]" xlator=replicate
time="2018-10-10 10:05:41.469522" level=info msg="Registered validation function for xlator" source="[load.go:140:xlator.loadXlator]" xlator=quota
time="2018-10-10 10:05:46.504293" level=error msg="failed to start embedded store" error="dial tcp 10.233.17.123:2379: getsockopt: no route to host" source="[embed.go:36:store.newEmbedStore]"
time="2018-10-10 10:05:46.504444" level=fatal msg="Failed to initialize store (etcd client)" error="dial tcp 10.233.17.123:2379: getsockopt: no route to host" source="[main.go:101:main.main]"
time="2018-10-10 10:08:41.370845" level=info msg="loaded configuration from file" file=/etc/glusterd2/glusterd2.toml source="[config.go:109:main.dumpConfigToLog]"
time="2018-10-10 10:08:41.382629" level=info msg="Registered validation function for xlator" source="[load.go:140:xlator.loadXlator]" xlator=afr
time="2018-10-10 10:08:41.384042" level=info msg="Registered validation function for xlator" source="[load.go:140:xlator.loadXlator]" xlator=dht
time="2018-10-10 10:08:41.389353" level=info msg="Registered validation function for xlator" source="[load.go:140:xlator.loadXlator]" xlator=distribute
time="2018-10-10 10:08:41.393253" level=info msg="Registered validation function for xlator" source="[load.go:140:xlator.loadXlator]" xlator=replicate
time="2018-10-10 10:08:41.425636" level=info msg="Registered validation function for xlator" source="[load.go:140:xlator.loadXlator]" xlator=quota
time="2018-10-10 10:11:41.331293" level=info msg="loaded configuration from file" file=/etc/glusterd2/glusterd2.toml source="[config.go:109:main.dumpConfigToLog]"
time="2018-10-10 10:11:41.343262" level=info msg="Registered validation function for xlator" source="[load.go:140:xlator.loadXlator]" xlator=afr
time="2018-10-10 10:11:41.344668" level=info msg="Registered validation function for xlator" source="[load.go:140:xlator.loadXlator]" xlator=dht
time="2018-10-10 10:11:41.347779" level=info msg="Registered validation function for xlator" source="[load.go:140:xlator.loadXlator]" xlator=distribute
time="2018-10-10 10:11:41.350810" level=info msg="Registered validation function for xlator" source="[load.go:140:xlator.loadXlator]" xlator=replicate
time="2018-10-10 10:11:41.381568" level=info msg="Registered validation function for xlator" source="[load.go:140:xlator.loadXlator]" xlator=quota
time="2018-10-10 10:11:49.226277" level=error msg="failed to start embedded store" error="context deadline exceeded" source="[embed.go:36:store.newEmbedStore]"
time="2018-10-10 10:11:49.226442" level=fatal msg="Failed to initialize store (etcd client)" error="context deadline exceeded" source="[main.go:101:main.main]"

@Madhu-1
Copy link
Member

Madhu-1 commented Oct 11, 2018

@kshlmI think we have some issue with ETCD cluster deployed by the operator. any thoughts on this?

@rmadaka
Copy link
Author

rmadaka commented Oct 15, 2018

Etcd pods status went to completed state after reboot/delete of GD2 pods or after reboot of kube nodes.

kubectl -n gcs get all
NAME READY STATUS RESTARTS AGE
pod/csi-attacher-glusterfsplugin-0 2/2 Running 0 3h28m
pod/csi-nodeplugin-glusterfsplugin-2tzrs 2/2 Running 2 3h28m
pod/csi-nodeplugin-glusterfsplugin-bbcgc 2/2 Running 0 3h28m
pod/csi-nodeplugin-glusterfsplugin-xbsz9 2/2 Running 2 3h28m
pod/csi-provisioner-glusterfsplugin-0 2/2 Running 0 3h28m
pod/etcd-7r9xtsmpnc 0/1 Completed 0 3h30m
pod/etcd-dq8vbpql2q 0/1 Completed 0 3h29m
pod/etcd-lbr4cvgfs4 0/1 Completed 0 3h30m
pod/etcd-operator-7cb5bd459b-ldj6x 1/1 Running 0 3h31m
pod/gluster-kube1-0 0/1 CrashLoopBackOff 7 27m
pod/gluster-kube2-0 1/1 Running 7 28m
pod/gluster-kube3-0 1/1 Running 1 27m

@JohnStrunk JohnStrunk added the GCS/0.2 GCS 0.2 release label Oct 18, 2018
@aravindavk
Copy link
Member

error message is saying trying to start embeded store. Is there a chance glusterd2 pod loosing configuration set via env options(like noembed=true)? @kshlm

time="2018-10-10 10:11:49.226277" level=error msg="failed to start embedded store" error="context deadline exceeded" source="[embed.go:36:store.newEmbedStore]"

@kshlm
Copy link
Member

kshlm commented Oct 24, 2018

error message is saying trying to start embeded store. Is there a chance glusterd2 pod loosing configuration set via env options(like noembed=true)? @kshlm

time="2018-10-10 10:11:49.226277" level=error msg="failed to start embedded store" error="context deadline exceeded" source="[embed.go:36:store.newEmbedStore]"

This is surprising. I need to look into this, and the etcd-operator issues.

@rmadaka
Copy link
Author

rmadaka commented Oct 25, 2018

Two pvcs mounted to 40 app pods, started running I/O's on one of the mount point. while I/O's are running on mount point, parallel trying to create 30 more app pods with same two pvc mount point.

ETCD pods and glusterd2 pods status went to below state.

NAME                                       READY   STATUS             RESTARTS   AGE
pod/csi-attacher-glusterfsplugin-0         2/2     Running            0          39h
pod/csi-nodeplugin-glusterfsplugin-5btkb   2/2     Running            0          39h
pod/csi-nodeplugin-glusterfsplugin-jg5r6   2/2     Running            0          39h
pod/csi-nodeplugin-glusterfsplugin-llwmz   2/2     Running            0          39h
pod/csi-provisioner-glusterfsplugin-0      2/2     Running            0          39h
pod/etcd-9m6lr28xb4                        0/1     Error              0          39h
pod/etcd-d6msrdt5b5                        0/1     Completed          0          39h
pod/etcd-operator-7cb5bd459b-dq86s         1/1     Running            0          39h
pod/etcd-tn7np2mzfd                        0/1     Running            0          39h
pod/gluster-kube1-0                        1/1     Running            0          39h
pod/gluster-kube2-0                        0/1     CrashLoopBackOff   183        39h
pod/gluster-kube3-0                        0/1     CrashLoopBackOff   185        39h

@Madhu-1
Copy link
Member

Madhu-1 commented Oct 25, 2018

@rmadaka can you provide some logs from ETCD pods as well, that would be helpful

@rmadaka
Copy link
Author

rmadaka commented Oct 25, 2018

Create one pvc and mounte to app pod. Login to gd2 pod and kill the one brick then start running I/O's on mount point.

ETCD pods status went to below state.

pod/csi-attacher-glusterfsplugin-0         2/2     Running     1          40h
pod/csi-nodeplugin-glusterfsplugin-5xjkb   2/2     Running     0          40h
pod/csi-nodeplugin-glusterfsplugin-hndpk   2/2     Running     0          40h
pod/csi-nodeplugin-glusterfsplugin-t4dvj   2/2     Running     0          40h
pod/csi-provisioner-glusterfsplugin-0      2/2     Running     0          40h
pod/etcd-4czmcdvp6m                        0/1     Completed   0          40h
pod/etcd-c2ljdps9hf                        0/1     Completed   0          40h
pod/etcd-operator-7cb5bd459b-hpms7         1/1     Running     0          40h
pod/etcd-spxbvfltfd                        0/1     Completed   0          40h
pod/gluster-kube1-0                        1/1     Running     224        40h
pod/gluster-kube2-0                        1/1     Running     0          40h
pod/gluster-kube3-0                        1/1     Running     0          40h

@rmadaka
Copy link
Author

rmadaka commented Oct 25, 2018

This logs for ETCD pod which is in Error state:

2018-10-24 13:38:13.021082 I | rafthttp: established a TCP streaming connection with peer f3246e3c0671bbf8 (stream Message reader)
2018-10-24 13:38:13.021342 I | raft: 8b0591e77e627785 [term: 57] ignored a MsgVoteResp message with lower term from f3246e3c0671bbf8 [term: 50]
2018-10-24 13:38:13.021355 I | raft: 8b0591e77e627785 [term: 57] ignored a MsgVote message with lower term from f3246e3c0671bbf8 [term: 51]
2018-10-24 13:38:13.021367 I | raft: 8b0591e77e627785 [term: 57] ignored a MsgVote message with lower term from f3246e3c0671bbf8 [term: 52]
2018-10-24 13:38:13.021377 I | raft: 8b0591e77e627785 [term: 57] ignored a MsgVote message with lower term from f3246e3c0671bbf8 [term: 53]
2018-10-24 13:38:13.021388 I | raft: 8b0591e77e627785 [term: 57] ignored a MsgVote message with lower term from f3246e3c0671bbf8 [term: 54]
2018-10-24 13:38:13.021395 I | raft: 8b0591e77e627785 [term: 57] ignored a MsgVote message with lower term from f3246e3c0671bbf8 [term: 55]
2018-10-24 13:38:13.021440 I | raft: 8b0591e77e627785 [term: 57] ignored a MsgVote message with lower term from f3246e3c0671bbf8 [term: 56]
2018-10-24 13:38:13.021460 I | raft: 8b0591e77e627785 [logterm: 36, index: 651, vote: 0] cast MsgVote for f3246e3c0671bbf8 [logterm: 55, index: 653] at term 57
2018-10-24 13:38:13.023043 W | rafthttp: closed an existing TCP streaming connection with peer f3246e3c0671bbf8 (stream Message writer)
2018-10-24 13:38:13.023066 I | rafthttp: established a TCP streaming connection with peer f3246e3c0671bbf8 (stream Message writer)
2018-10-24 13:38:13.024950 W | rafthttp: closed an existing TCP streaming connection with peer f3246e3c0671bbf8 (stream Message writer)
2018-10-24 13:38:13.024966 I | rafthttp: established a TCP streaming connection with peer f3246e3c0671bbf8 (stream Message writer)
2018-10-24 13:38:13.027176 I | rafthttp: peer 360e47b7f2484e5e became active
2018-10-24 13:38:13.027208 W | rafthttp: closed an existing TCP streaming connection with peer 360e47b7f2484e5e (stream MsgApp v2 writer)
2018-10-24 13:38:13.027218 I | rafthttp: established a TCP streaming connection with peer 360e47b7f2484e5e (stream MsgApp v2 writer)
2018-10-24 13:38:13.027996 W | rafthttp: closed an existing TCP streaming connection with peer 360e47b7f2484e5e (stream Message writer)
2018-10-24 13:38:13.028015 I | rafthttp: established a TCP streaming connection with peer 360e47b7f2484e5e (stream Message writer)
2018-10-24 13:38:13.028518 W | rafthttp: closed an existing TCP streaming connection with peer f3246e3c0671bbf8 (stream MsgApp v2 writer)
2018-10-24 13:38:13.028533 I | rafthttp: established a TCP streaming connection with peer f3246e3c0671bbf8 (stream MsgApp v2 writer)
2018-10-24 13:38:13.029135 W | rafthttp: closed an existing TCP streaming connection with peer f3246e3c0671bbf8 (stream MsgApp v2 writer)
2018-10-24 13:38:13.029154 I | rafthttp: established a TCP streaming connection with peer f3246e3c0671bbf8 (stream MsgApp v2 writer)
2018-10-24 13:38:13.353836 W | rafthttp: closed an existing TCP streaming connection with peer f3246e3c0671bbf8 (stream MsgApp v2 writer)
2018-10-24 13:38:13.353879 I | rafthttp: established a TCP streaming connection with peer f3246e3c0671bbf8 (stream MsgApp v2 writer)
2018-10-24 13:38:17.579194 E | rafthttp: failed to heartbeat 360e47b7f2484e5e on stream Message (write tcp 10.233.66.5:2380->10.233.64.4:36196: write: broken pipe)
2018-10-24 13:38:17.579235 I | rafthttp: peer 360e47b7f2484e5e became inactive
2018-10-24 13:38:17.580251 W | rafthttp: lost the TCP streaming connection with peer 360e47b7f2484e5e (stream Message writer)
2018-10-24 13:38:18.794601 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context deadline exceeded" took too long (4.998819018s) to execute
2018-10-24 13:38:19.534719 W | etcdserver: timed out waiting for read index response
2018-10-24 13:38:19.547484 W | etcdserver: read-only range request "key:\"foo\" " with result "range_response_count:0 size:5" took too long (4.107627251s) to execute
2018-10-24 13:38:19.547733 W | etcdserver: read-only range request "key:\"foo\" " with result "range_response_count:0 size:5" took too long (693.90722ms) to execute
2018-10-24 13:38:29.340715 I | raft: 8b0591e77e627785 is starting a new election at term 57
2018-10-24 13:38:29.340786 I | raft: 8b0591e77e627785 became candidate at term 58
2018-10-24 13:38:29.340811 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 58
2018-10-24 13:38:29.340839 I | raft: 8b0591e77e627785 [logterm: 57, index: 654] sent MsgVote request to f3246e3c0671bbf8 at term 58
2018-10-24 13:38:29.340876 I | raft: 8b0591e77e627785 [logterm: 57, index: 654] sent MsgVote request to 360e47b7f2484e5e at term 58
2018-10-24 13:38:29.340897 I | raft: raft.node: 8b0591e77e627785 lost leader f3246e3c0671bbf8 at term 58
2018-10-24 13:38:30.847055 I | raft: 8b0591e77e627785 is starting a new election at term 58
2018-10-24 13:38:30.847120 I | raft: 8b0591e77e627785 became candidate at term 59
2018-10-24 13:38:30.847138 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 59
2018-10-24 13:38:30.847157 I | raft: 8b0591e77e627785 [logterm: 57, index: 654] sent MsgVote request to 360e47b7f2484e5e at term 59
2018-10-24 13:38:30.847173 I | raft: 8b0591e77e627785 [logterm: 57, index: 654] sent MsgVote request to f3246e3c0671bbf8 at term 59
2018-10-24 13:38:31.065623 I | raft: 8b0591e77e627785 received MsgVoteResp from f3246e3c0671bbf8 at term 59
2018-10-24 13:38:31.065671 I | raft: 8b0591e77e627785 [quorum:2] has received 2 MsgVoteResp votes and 0 vote rejections
2018-10-24 13:38:31.065706 I | raft: 8b0591e77e627785 became leader at term 59
2018-10-24 13:38:31.065725 I | raft: raft.node: 8b0591e77e627785 elected leader 8b0591e77e627785 at term 59
2018-10-24 13:38:33.943556 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context canceled" took too long (4.999369642s) to execute
WARNING: 2018/10/24 13:38:33 grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"
2018-10-24 13:38:35.944291 W | etcdserver: timed out waiting for read index response
2018-10-24 13:38:35.947047 W | etcdserver: read-only range request "key:\"foo\" " with result "range_response_count:0 size:5" took too long (1.933794766s) to execute
2018-10-24 13:38:43.374526 I | rafthttp: peer 360e47b7f2484e5e became active
2018-10-24 13:38:43.840740 W | rafthttp: dropped internal raft message to 360e47b7f2484e5e since pipeline's sending buffer is full (bad/overloaded network)
2018-10-24 13:38:45.174292 W | rafthttp: dropped internal raft message to 360e47b7f2484e5e since pipeline's sending buffer is full (bad/overloaded network) [merged 15 repeated lines in 1.33s]
2018-10-24 13:38:45.220480 E | rafthttp: failed to dial 360e47b7f2484e5e on stream Message (read tcp 10.233.66.5:40042->10.233.64.4:2380: i/o timeout)
2018-10-24 13:38:45.220532 I | rafthttp: peer 360e47b7f2484e5e became inactive
2018-10-24 13:38:50.492950 I | rafthttp: peer 360e47b7f2484e5e became active
2018-10-24 13:38:50.869323 I | rafthttp: established a TCP streaming connection with peer 360e47b7f2484e5e (stream Message reader)
2018-10-24 13:38:52.340739 W | rafthttp: dropped internal raft message to 360e47b7f2484e5e since pipeline's sending buffer is full (bad/overloaded network)
2018-10-24 13:38:54.174227 W | rafthttp: dropped internal raft message to 360e47b7f2484e5e since pipeline's sending buffer is full (bad/overloaded network) [merged 19 repeated lines in 1.83s]
2018-10-24 13:38:54.366226 W | rafthttp: lost the TCP streaming connection with peer 360e47b7f2484e5e (stream Message reader)
2018-10-24 13:38:54.367814 I | rafthttp: established a TCP streaming connection with peer 360e47b7f2484e5e (stream MsgApp v2 reader)
2018-10-24 13:38:55.611658 I | rafthttp: established a TCP streaming connection with peer 360e47b7f2484e5e (stream Message reader)
2018-10-24 13:38:56.174150 W | rafthttp: dropped internal raft message to 360e47b7f2484e5e since pipeline's sending buffer is full (bad/overloaded network) [merged 13 repeated lines in 2s]
2018-10-24 13:38:58.174061 W | rafthttp: dropped internal raft message to 360e47b7f2484e5e since pipeline's sending buffer is full (bad/overloaded network) [merged 20 repeated lines in 2s]
2018-10-24 13:38:59.177047 W | rafthttp: dropped internal raft message to 360e47b7f2484e5e since pipeline's sending buffer is full (bad/overloaded network) [merged 11 repeated lines in 1.01s]
2018-10-24 13:38:59.285209 W | etcdserver: read-only range request "key:\"foo\" " with result "range_response_count:0 size:5" took too long (247.472805ms) to execute
2018-10-24 13:38:59.368283 W | rafthttp: lost the TCP streaming connection with peer 360e47b7f2484e5e (stream MsgApp v2 reader)
2018-10-24 13:38:59.368356 E | rafthttp: failed to read 360e47b7f2484e5e on stream MsgApp v2 (read tcp 10.233.66.5:40058->10.233.64.4:2380: i/o timeout)
2018-10-24 13:38:59.368366 I | rafthttp: peer 360e47b7f2484e5e became inactive
2018-10-24 13:39:00.611995 W | rafthttp: lost the TCP streaming connection with peer 360e47b7f2484e5e (stream Message reader)
2018-10-24 13:39:01.111318 I | rafthttp: peer 360e47b7f2484e5e became active
2018-10-24 13:39:01.174333 W | rafthttp: dropped internal raft message to 360e47b7f2484e5e since pipeline's sending buffer is full (bad/overloaded network) [merged 2 repeated lines in 1.99s]
2018-10-24 13:39:03.174133 W | rafthttp: dropped internal raft message to 360e47b7f2484e5e since pipeline's sending buffer is full (bad/overloaded network) [merged 20 repeated lines in 2s]
2018-10-24 13:39:04.174347 W | rafthttp: dropped internal raft message to 360e47b7f2484e5e since pipeline's sending buffer is full (bad/overloaded network) [merged 11 repeated lines in 1s]
2018-10-24 13:39:04.476976 E | rafthttp: failed to dial 360e47b7f2484e5e on stream MsgApp v2 (read tcp 10.233.66.5:40072->10.233.64.4:2380: i/o timeout)
2018-10-24 13:39:04.477009 I | rafthttp: peer 360e47b7f2484e5e became inactive
2018-10-24 13:39:05.174224 W | rafthttp: dropped internal raft message to 360e47b7f2484e5e since pipeline's sending buffer is full (bad/overloaded network) [merged 3 repeated lines in 1s]
2018-10-24 13:39:14.040692 W | raft: 8b0591e77e627785 stepped down to follower since quorum is not active
2018-10-24 13:39:14.040750 I | raft: 8b0591e77e627785 became follower at term 59
2018-10-24 13:39:14.040760 I | raft: raft.node: 8b0591e77e627785 lost leader 8b0591e77e627785 at term 59
2018-10-24 13:39:15.840946 I | raft: 8b0591e77e627785 is starting a new election at term 59
2018-10-24 13:39:15.841033 I | raft: 8b0591e77e627785 became candidate at term 60
2018-10-24 13:39:15.841063 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 60
2018-10-24 13:39:15.841099 I | raft: 8b0591e77e627785 [logterm: 59, index: 658] sent MsgVote request to 360e47b7f2484e5e at term 60
2018-10-24 13:39:15.841118 I | raft: 8b0591e77e627785 [logterm: 59, index: 658] sent MsgVote request to f3246e3c0671bbf8 at term 60
2018-10-24 13:39:16.023148 I | rafthttp: peer 360e47b7f2484e5e became active
2018-10-24 13:39:17.140685 I | raft: 8b0591e77e627785 is starting a new election at term 60
2018-10-24 13:39:17.140737 I | raft: 8b0591e77e627785 became candidate at term 61
2018-10-24 13:39:17.140750 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 61
2018-10-24 13:39:17.140763 I | raft: 8b0591e77e627785 [logterm: 59, index: 658] sent MsgVote request to f3246e3c0671bbf8 at term 61
2018-10-24 13:39:17.140773 I | raft: 8b0591e77e627785 [logterm: 59, index: 658] sent MsgVote request to 360e47b7f2484e5e at term 61
2018-10-24 13:39:18.140662 I | raft: 8b0591e77e627785 is starting a new election at term 61
2018-10-24 13:39:18.140712 I | raft: 8b0591e77e627785 became candidate at term 62
2018-10-24 13:39:18.140726 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 62
2018-10-24 13:39:18.140737 I | raft: 8b0591e77e627785 [logterm: 59, index: 658] sent MsgVote request to f3246e3c0671bbf8 at term 62
2018-10-24 13:39:18.140757 I | raft: 8b0591e77e627785 [logterm: 59, index: 658] sent MsgVote request to 360e47b7f2484e5e at term 62
2018-10-24 13:39:18.215529 I | raft: 8b0591e77e627785 [term: 62] ignored a MsgVoteResp message with lower term from f3246e3c0671bbf8 [term: 60]
2018-10-24 13:39:18.215571 I | raft: 8b0591e77e627785 [term: 62] ignored a MsgVoteResp message with lower term from f3246e3c0671bbf8 [term: 61]
2018-10-24 13:39:18.215596 I | raft: 8b0591e77e627785 received MsgVoteResp from f3246e3c0671bbf8 at term 62
2018-10-24 13:39:18.215613 I | raft: 8b0591e77e627785 [quorum:2] has received 2 MsgVoteResp votes and 0 vote rejections
2018-10-24 13:39:18.215640 I | raft: 8b0591e77e627785 became leader at term 62
2018-10-24 13:39:18.215661 I | raft: raft.node: 8b0591e77e627785 elected leader 8b0591e77e627785 at term 62
2018-10-24 13:39:18.340648 W | rafthttp: dropped internal raft message to 360e47b7f2484e5e since pipeline's sending buffer is full (bad/overloaded network)
2018-10-24 13:39:18.950670 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context deadline exceeded" took too long (4.999095143s) to execute
2018-10-24 13:39:19.140795 W | raft: 8b0591e77e627785 stepped down to follower since quorum is not active
2018-10-24 13:39:19.140946 I | raft: 8b0591e77e627785 became follower at term 62
2018-10-24 13:39:19.140972 I | raft: raft.node: 8b0591e77e627785 lost leader 8b0591e77e627785 at term 62
2018-10-24 13:39:20.140698 I | raft: 8b0591e77e627785 is starting a new election at term 62
2018-10-24 13:39:20.140755 I | raft: 8b0591e77e627785 became candidate at term 63
2018-10-24 13:39:20.140771 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 63
2018-10-24 13:39:20.140785 I | raft: 8b0591e77e627785 [logterm: 62, index: 659] sent MsgVote request to f3246e3c0671bbf8 at term 63
2018-10-24 13:39:20.140797 I | raft: 8b0591e77e627785 [logterm: 62, index: 659] sent MsgVote request to 360e47b7f2484e5e at term 63
2018-10-24 13:39:20.174227 W | rafthttp: dropped internal raft message to 360e47b7f2484e5e since pipeline's sending buffer is full (bad/overloaded network) [merged 8 repeated lines in 1.83s]
2018-10-24 13:39:20.438895 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context canceled" took too long (5.000705008s) to execute
WARNING: 2018/10/24 13:39:20 grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"
2018-10-24 13:39:20.589590 E | rafthttp: failed to dial 360e47b7f2484e5e on stream MsgApp v2 (read tcp 10.233.66.5:40100->10.233.64.4:2380: i/o timeout)
2018-10-24 13:39:20.589636 I | rafthttp: peer 360e47b7f2484e5e became inactive
2018-10-24 13:39:20.951690 W | etcdserver: timed out waiting for read index response
2018-10-24 13:39:21.164403 I | rafthttp: peer 360e47b7f2484e5e became active
2018-10-24 13:39:21.485212 W | etcdserver: read-only range request "key:\"gluster-8b30817b-61cd-49eb-be27-5b7e92a10337/config/events/webhooks/\" range_end:\"gluster-8b30817b-61cd-49eb-be27-5b7e92a10337/config/events/webhooks0\" " with result "error:context deadline exceeded" took too long (289.363566ms) to execute
2018-10-24 13:39:21.534312 I | raft: 8b0591e77e627785 [term: 63] ignored a MsgAppResp message with lower term from f3246e3c0671bbf8 [term: 62]
2018-10-24 13:39:21.534366 I | raft: 8b0591e77e627785 [term: 63] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 62]
2018-10-24 13:39:21.534389 I | raft: 8b0591e77e627785 [term: 63] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 62]
2018-10-24 13:39:21.534403 I | raft: 8b0591e77e627785 [term: 63] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 62]
2018-10-24 13:39:21.534421 I | raft: 8b0591e77e627785 [term: 63] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 62]
2018-10-24 13:39:21.534434 I | raft: 8b0591e77e627785 [term: 63] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 62]
2018-10-24 13:39:21.534459 I | raft: 8b0591e77e627785 [term: 63] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 62]
2018-10-24 13:39:21.534480 I | raft: 8b0591e77e627785 [term: 63] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 62]
2018-10-24 13:39:21.534542 I | raft: 8b0591e77e627785 [term: 63] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 62]
2018-10-24 13:39:21.534570 I | raft: 8b0591e77e627785 [term: 63] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 62]
2018-10-24 13:39:21.740755 I | raft: 8b0591e77e627785 is starting a new election at term 63
2018-10-24 13:39:21.740904 I | raft: 8b0591e77e627785 became candidate at term 64
2018-10-24 13:39:21.740927 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 64
2018-10-24 13:39:21.740950 I | raft: 8b0591e77e627785 [logterm: 62, index: 659] sent MsgVote request to 360e47b7f2484e5e at term 64
2018-10-24 13:39:21.740975 I | raft: 8b0591e77e627785 [logterm: 62, index: 659] sent MsgVote request to f3246e3c0671bbf8 at term 64
2018-10-24 13:39:23.240751 I | raft: 8b0591e77e627785 is starting a new election at term 64
2018-10-24 13:39:23.240828 I | raft: 8b0591e77e627785 became candidate at term 65
2018-10-24 13:39:23.240847 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 65
2018-10-24 13:39:23.241050 I | raft: 8b0591e77e627785 [logterm: 62, index: 659] sent MsgVote request to f3246e3c0671bbf8 at term 65
2018-10-24 13:39:23.241077 I | raft: 8b0591e77e627785 [logterm: 62, index: 659] sent MsgVote request to 360e47b7f2484e5e at term 65
2018-10-24 13:39:24.007219 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context deadline exceeded" took too long (4.999270453s) to execute
2018-10-24 13:39:24.240638 I | raft: 8b0591e77e627785 is starting a new election at term 65
2018-10-24 13:39:24.240692 I | raft: 8b0591e77e627785 became candidate at term 66
2018-10-24 13:39:24.240706 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 66
2018-10-24 13:39:24.240731 I | raft: 8b0591e77e627785 [logterm: 62, index: 659] sent MsgVote request to 360e47b7f2484e5e at term 66
2018-10-24 13:39:24.240742 I | raft: 8b0591e77e627785 [logterm: 62, index: 659] sent MsgVote request to f3246e3c0671bbf8 at term 66
2018-10-24 13:39:25.940625 I | raft: 8b0591e77e627785 is starting a new election at term 66
2018-10-24 13:39:25.940668 I | raft: 8b0591e77e627785 became candidate at term 67
2018-10-24 13:39:25.940683 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 67
2018-10-24 13:39:25.940696 I | raft: 8b0591e77e627785 [logterm: 62, index: 659] sent MsgVote request to f3246e3c0671bbf8 at term 67
2018-10-24 13:39:25.940706 I | raft: 8b0591e77e627785 [logterm: 62, index: 659] sent MsgVote request to 360e47b7f2484e5e at term 67
2018-10-24 13:39:26.195791 W | etcdserver: read-only range request "key:\"gluster-8b30817b-61cd-49eb-be27-5b7e92a10337/config/events/webhooks/\" range_end:\"gluster-8b30817b-61cd-49eb-be27-5b7e92a10337/config/events/webhooks0\" " with result "error:context deadline exceeded" took too long (4.99990853s) to execute
2018-10-24 13:39:26.196084 W | etcdserver: read-only range request "key:\"gluster-8b30817b-61cd-49eb-be27-5b7e92a10337/config/events/webhooks/\" range_end:\"gluster-8b30817b-61cd-49eb-be27-5b7e92a10337/config/events/webhooks0\" " with result "error:context deadline exceeded" took too long (5.000269182s) to execute
2018-10-24 13:39:26.203995 W | rafthttp: dropped internal raft message to 360e47b7f2484e5e since pipeline's sending buffer is full (bad/overloaded network)
2018-10-24 13:39:26.557187 E | rafthttp: failed to dial 360e47b7f2484e5e on stream MsgApp v2 (read tcp 10.233.66.5:40116->10.233.64.4:2380: i/o timeout)
2018-10-24 13:39:26.557219 I | rafthttp: peer 360e47b7f2484e5e became inactive
2018-10-24 13:39:27.340651 I | raft: 8b0591e77e627785 is starting a new election at term 67
2018-10-24 13:39:27.340719 I | raft: 8b0591e77e627785 became candidate at term 68
2018-10-24 13:39:27.340738 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 68
2018-10-24 13:39:27.340797 I | raft: 8b0591e77e627785 [logterm: 62, index: 659] sent MsgVote request to f3246e3c0671bbf8 at term 68
2018-10-24 13:39:27.340815 I | raft: 8b0591e77e627785 [logterm: 62, index: 659] sent MsgVote request to 360e47b7f2484e5e at term 68
2018-10-24 13:39:27.868670 I | raft: 8b0591e77e627785 [term: 68] ignored a MsgVote message with lower term from f3246e3c0671bbf8 [term: 63]
2018-10-24 13:39:27.868719 I | raft: 8b0591e77e627785 [term: 68] ignored a MsgVoteResp message with lower term from f3246e3c0671bbf8 [term: 67]
2018-10-24 13:39:27.868749 I | raft: 8b0591e77e627785 received MsgVoteResp from f3246e3c0671bbf8 at term 68
2018-10-24 13:39:27.868766 I | raft: 8b0591e77e627785 [quorum:2] has received 2 MsgVoteResp votes and 0 vote rejections
2018-10-24 13:39:27.868793 I | raft: 8b0591e77e627785 became leader at term 68
2018-10-24 13:39:27.868807 I | raft: raft.node: 8b0591e77e627785 elected leader 8b0591e77e627785 at term 68
2018-10-24 13:39:27.951973 W | etcdserver: timed out waiting for read index response
2018-10-24 13:39:29.071232 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context canceled" took too long (4.999476189s) to execute
WARNING: 2018/10/24 13:39:29 grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"
2018-10-24 13:39:34.123235 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context canceled" took too long (4.999528621s) to execute
WARNING: 2018/10/24 13:39:34 grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"
2018-10-24 13:39:34.952216 W | etcdserver: timed out waiting for read index response
2018-10-24 13:39:35.140757 W | etcdserver: read-only range request "key:\"foo\" " with result "range_response_count:0 size:5" took too long (964.220089ms) to execute
2018-10-24 13:39:36.840684 W | raft: 8b0591e77e627785 stepped down to follower since quorum is not active
2018-10-24 13:39:36.840749 I | raft: 8b0591e77e627785 became follower at term 68
2018-10-24 13:39:36.840760 I | raft: raft.node: 8b0591e77e627785 lost leader 8b0591e77e627785 at term 68
2018-10-24 13:39:38.140724 I | raft: 8b0591e77e627785 is starting a new election at term 68
2018-10-24 13:39:38.140785 I | raft: 8b0591e77e627785 became candidate at term 69
2018-10-24 13:39:38.140802 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 69
2018-10-24 13:39:38.140817 I | raft: 8b0591e77e627785 [logterm: 68, index: 660] sent MsgVote request to f3246e3c0671bbf8 at term 69
2018-10-24 13:39:38.140829 I | raft: 8b0591e77e627785 [logterm: 68, index: 660] sent MsgVote request to 360e47b7f2484e5e at term 69
2018-10-24 13:39:39.641008 I | raft: 8b0591e77e627785 is starting a new election at term 69
2018-10-24 13:39:39.641429 I | raft: 8b0591e77e627785 became candidate at term 70
2018-10-24 13:39:39.641445 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 70
2018-10-24 13:39:39.641457 I | raft: 8b0591e77e627785 [logterm: 68, index: 660] sent MsgVote request to f3246e3c0671bbf8 at term 70
2018-10-24 13:39:39.641468 I | raft: 8b0591e77e627785 [logterm: 68, index: 660] sent MsgVote request to 360e47b7f2484e5e at term 70
2018-10-24 13:39:39.771003 I | raft: 8b0591e77e627785 received MsgVoteResp from f3246e3c0671bbf8 at term 70
2018-10-24 13:39:39.771042 I | raft: 8b0591e77e627785 [quorum:2] has received 2 MsgVoteResp votes and 0 vote rejections
2018-10-24 13:39:39.771073 I | raft: 8b0591e77e627785 became leader at term 70
2018-10-24 13:39:39.771095 I | raft: raft.node: 8b0591e77e627785 elected leader 8b0591e77e627785 at term 70
2018-10-24 13:39:43.946780 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context canceled" took too long (5.000370692s) to execute
WARNING: 2018/10/24 13:39:43 grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"
2018-10-24 13:39:45.946587 W | etcdserver: timed out waiting for read index response
2018-10-24 13:39:46.185585 W | etcdserver: read-only range request "key:\"foo\" " with result "range_response_count:0 size:5" took too long (2.187585741s) to execute
2018-10-24 13:40:12.740689 W | raft: 8b0591e77e627785 stepped down to follower since quorum is not active
2018-10-24 13:40:12.740745 I | raft: 8b0591e77e627785 became follower at term 70
2018-10-24 13:40:12.740764 I | raft: raft.node: 8b0591e77e627785 lost leader 8b0591e77e627785 at term 70
2018-10-24 13:40:13.464591 I | rafthttp: peer 360e47b7f2484e5e became active
2018-10-24 13:40:13.740983 I | raft: 8b0591e77e627785 is starting a new election at term 70
2018-10-24 13:40:13.741038 I | raft: 8b0591e77e627785 became candidate at term 71
2018-10-24 13:40:13.741052 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 71
2018-10-24 13:40:13.741064 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to f3246e3c0671bbf8 at term 71
2018-10-24 13:40:13.741074 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to 360e47b7f2484e5e at term 71
2018-10-24 13:40:13.763982 I | raft: 8b0591e77e627785 [term: 71] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 70]
2018-10-24 13:40:13.764008 I | raft: 8b0591e77e627785 [term: 71] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 70]
2018-10-24 13:40:13.764026 I | raft: 8b0591e77e627785 [term: 71] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 70]
2018-10-24 13:40:13.764034 I | raft: 8b0591e77e627785 [term: 71] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 70]
2018-10-24 13:40:13.764045 I | raft: 8b0591e77e627785 [term: 71] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 70]
2018-10-24 13:40:13.764053 I | raft: 8b0591e77e627785 [term: 71] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 70]
2018-10-24 13:40:13.764063 I | raft: 8b0591e77e627785 [term: 71] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 70]
2018-10-24 13:40:13.764071 I | raft: 8b0591e77e627785 [term: 71] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 70]
2018-10-24 13:40:13.764081 I | raft: 8b0591e77e627785 [term: 71] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 70]
2018-10-24 13:40:13.764096 I | raft: 8b0591e77e627785 [term: 71] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 70]
2018-10-24 13:40:13.764106 I | raft: 8b0591e77e627785 [term: 71] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 70]
2018-10-24 13:40:13.764113 I | raft: 8b0591e77e627785 [term: 71] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 70]
2018-10-24 13:40:13.764123 I | raft: 8b0591e77e627785 [term: 71] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 70]
2018-10-24 13:40:13.764130 I | raft: 8b0591e77e627785 [term: 71] ignored a MsgHeartbeatResp message with lower term from f3246e3c0671bbf8 [term: 70]
2018-10-24 13:40:14.840683 I | raft: 8b0591e77e627785 is starting a new election at term 71
2018-10-24 13:40:14.840758 I | raft: 8b0591e77e627785 became candidate at term 72
2018-10-24 13:40:14.840784 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 72
2018-10-24 13:40:14.840802 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to f3246e3c0671bbf8 at term 72
2018-10-24 13:40:14.840819 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to 360e47b7f2484e5e at term 72
2018-10-24 13:40:16.140736 I | raft: 8b0591e77e627785 is starting a new election at term 72
2018-10-24 13:40:16.140806 I | raft: 8b0591e77e627785 became candidate at term 73
2018-10-24 13:40:16.140829 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 73
2018-10-24 13:40:16.140854 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to f3246e3c0671bbf8 at term 73
2018-10-24 13:40:16.140901 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to 360e47b7f2484e5e at term 73
2018-10-24 13:40:18.040806 I | raft: 8b0591e77e627785 is starting a new election at term 73
2018-10-24 13:40:18.040904 I | raft: 8b0591e77e627785 became candidate at term 74
2018-10-24 13:40:18.040926 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 74
2018-10-24 13:40:18.040948 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to f3246e3c0671bbf8 at term 74
2018-10-24 13:40:18.040974 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to 360e47b7f2484e5e at term 74
2018-10-24 13:40:18.458600 E | rafthttp: failed to dial 360e47b7f2484e5e on stream MsgApp v2 (read tcp 10.233.66.5:40200->10.233.64.4:2380: i/o timeout)
2018-10-24 13:40:18.458660 I | rafthttp: peer 360e47b7f2484e5e became inactive
2018-10-24 13:40:18.945228 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context canceled" took too long (4.999681664s) to execute
WARNING: 2018/10/24 13:40:18 grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"
2018-10-24 13:40:19.440686 I | raft: 8b0591e77e627785 is starting a new election at term 74
2018-10-24 13:40:19.440768 I | raft: 8b0591e77e627785 became candidate at term 75
2018-10-24 13:40:19.440790 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 75
2018-10-24 13:40:19.440810 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to 360e47b7f2484e5e at term 75
2018-10-24 13:40:19.440839 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to f3246e3c0671bbf8 at term 75
2018-10-24 13:40:20.470493 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context deadline exceeded" took too long (4.99909002s) to execute
2018-10-24 13:40:20.945759 W | etcdserver: timed out waiting for read index response
2018-10-24 13:40:21.140674 I | raft: 8b0591e77e627785 is starting a new election at term 75
2018-10-24 13:40:21.140741 I | raft: 8b0591e77e627785 became candidate at term 76
2018-10-24 13:40:21.140758 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 76
2018-10-24 13:40:21.140771 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to f3246e3c0671bbf8 at term 76
2018-10-24 13:40:21.140822 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to 360e47b7f2484e5e at term 76
2018-10-24 13:40:22.580397 W | rafthttp: lost the TCP streaming connection with peer f3246e3c0671bbf8 (stream MsgApp v2 reader)
2018-10-24 13:40:22.580473 E | rafthttp: failed to read f3246e3c0671bbf8 on stream MsgApp v2 (read tcp 10.233.66.5:42604->10.233.65.4:2380: i/o timeout)
2018-10-24 13:40:22.580487 I | rafthttp: peer f3246e3c0671bbf8 became inactive
2018-10-24 13:40:22.580738 W | rafthttp: lost the TCP streaming connection with peer f3246e3c0671bbf8 (stream Message reader)
2018-10-24 13:40:22.740741 I | raft: 8b0591e77e627785 is starting a new election at term 76
2018-10-24 13:40:22.740816 I | raft: 8b0591e77e627785 became candidate at term 77
2018-10-24 13:40:22.740835 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 77
2018-10-24 13:40:22.740881 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to f3246e3c0671bbf8 at term 77
2018-10-24 13:40:22.740900 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to 360e47b7f2484e5e at term 77
2018-10-24 13:40:23.940671 I | raft: 8b0591e77e627785 is starting a new election at term 77
2018-10-24 13:40:23.940729 I | raft: 8b0591e77e627785 became candidate at term 78
2018-10-24 13:40:23.940744 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 78
2018-10-24 13:40:23.940763 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to f3246e3c0671bbf8 at term 78
2018-10-24 13:40:23.940793 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to 360e47b7f2484e5e at term 78
2018-10-24 13:40:24.003601 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context canceled" took too long (4.999337364s) to execute
WARNING: 2018/10/24 13:40:24 grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"
2018-10-24 13:40:25.740697 I | raft: 8b0591e77e627785 is starting a new election at term 78
2018-10-24 13:40:25.740779 I | raft: 8b0591e77e627785 became candidate at term 79
2018-10-24 13:40:25.740799 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 79
2018-10-24 13:40:25.740819 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to 360e47b7f2484e5e at term 79
2018-10-24 13:40:25.740840 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to f3246e3c0671bbf8 at term 79
2018-10-24 13:40:27.440679 I | raft: 8b0591e77e627785 is starting a new election at term 79
2018-10-24 13:40:27.440735 I | raft: 8b0591e77e627785 became candidate at term 80
2018-10-24 13:40:27.440751 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 80
2018-10-24 13:40:27.440765 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to f3246e3c0671bbf8 at term 80
2018-10-24 13:40:27.440775 I | raft: 8b0591e77e627785 [logterm: 70, index: 661] sent MsgVote request to 360e47b7f2484e5e at term 80
2018-10-24 13:40:27.929057 I | rafthttp: peer f3246e3c0671bbf8 became active
2018-10-24 13:40:27.929091 I | rafthttp: established a TCP streaming connection with peer f3246e3c0671bbf8 (stream Message reader)
2018-10-24 13:40:27.929433 I | rafthttp: established a TCP streaming connection with peer f3246e3c0671bbf8 (stream MsgApp v2 reader)
2018-10-24 13:40:27.945954 W | etcdserver: timed out waiting for read index response
2018-10-24 13:40:28.474087 I | raft: 8b0591e77e627785 [term: 80] ignored a MsgVoteResp message with lower term from f3246e3c0671bbf8 [term: 74]
2018-10-24 13:40:28.474135 I | raft: 8b0591e77e627785 [term: 80] ignored a MsgVoteResp message with lower term from f3246e3c0671bbf8 [term: 75]
2018-10-24 13:40:28.474158 I | raft: 8b0591e77e627785 [term: 80] ignored a MsgVoteResp message with lower term from f3246e3c0671bbf8 [term: 76]
2018-10-24 13:40:28.475986 I | raft: 8b0591e77e627785 [term: 80] ignored a MsgVoteResp message with lower term from f3246e3c0671bbf8 [term: 77]
2018-10-24 13:40:28.476023 I | raft: 8b0591e77e627785 [term: 80] ignored a MsgVoteResp message with lower term from f3246e3c0671bbf8 [term: 78]
2018-10-24 13:40:28.476298 I | raft: 8b0591e77e627785 [term: 80] ignored a MsgVoteResp message with lower term from f3246e3c0671bbf8 [term: 79]
2018-10-24 13:40:28.476349 I | raft: 8b0591e77e627785 received MsgVoteResp from f3246e3c0671bbf8 at term 80
2018-10-24 13:40:28.476367 I | raft: 8b0591e77e627785 [quorum:2] has received 2 MsgVoteResp votes and 0 vote rejections
2018-10-24 13:40:28.476396 I | raft: 8b0591e77e627785 became leader at term 80
2018-10-24 13:40:28.476425 I | raft: raft.node: 8b0591e77e627785 elected leader 8b0591e77e627785 at term 80
2018-10-24 13:40:29.069182 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context canceled" took too long (4.999034078s) to execute
WARNING: 2018/10/24 13:40:29 grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"
2018-10-24 13:40:32.440664 W | raft: 8b0591e77e627785 stepped down to follower since quorum is not active
2018-10-24 13:40:32.440720 I | raft: 8b0591e77e627785 became follower at term 80
2018-10-24 13:40:32.440730 I | raft: raft.node: 8b0591e77e627785 lost leader 8b0591e77e627785 at term 80
2018-10-24 13:40:33.440674 I | raft: 8b0591e77e627785 is starting a new election at term 80
2018-10-24 13:40:33.440735 I | raft: 8b0591e77e627785 became candidate at term 81
2018-10-24 13:40:33.440754 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 81
2018-10-24 13:40:33.440768 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to f3246e3c0671bbf8 at term 81
2018-10-24 13:40:33.440778 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to 360e47b7f2484e5e at term 81
2018-10-24 13:40:34.115801 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context canceled" took too long (4.999973817s) to execute
WARNING: 2018/10/24 13:40:34 grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"
2018-10-24 13:40:34.946185 W | etcdserver: timed out waiting for read index response
2018-10-24 13:40:35.240704 I | raft: 8b0591e77e627785 is starting a new election at term 81
2018-10-24 13:40:35.240762 I | raft: 8b0591e77e627785 became candidate at term 82
2018-10-24 13:40:35.240785 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 82
2018-10-24 13:40:35.240819 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to f3246e3c0671bbf8 at term 82
2018-10-24 13:40:35.240839 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to 360e47b7f2484e5e at term 82
2018-10-24 13:40:36.373046 W | rafthttp: lost the TCP streaming connection with peer f3246e3c0671bbf8 (stream Message reader)
2018-10-24 13:40:36.373104 E | rafthttp: failed to read f3246e3c0671bbf8 on stream Message (read tcp 10.233.66.5:42884->10.233.65.4:2380: i/o timeout)
2018-10-24 13:40:36.373111 I | rafthttp: peer f3246e3c0671bbf8 became inactive
2018-10-24 13:40:36.540671 I | raft: 8b0591e77e627785 is starting a new election at term 82
2018-10-24 13:40:36.540733 I | raft: 8b0591e77e627785 became candidate at term 83
2018-10-24 13:40:36.540746 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 83
2018-10-24 13:40:36.540759 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to 360e47b7f2484e5e at term 83
2018-10-24 13:40:36.540770 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to f3246e3c0671bbf8 at term 83
2018-10-24 13:40:37.951669 W | rafthttp: lost the TCP streaming connection with peer f3246e3c0671bbf8 (stream MsgApp v2 reader)
2018-10-24 13:40:38.140764 I | raft: 8b0591e77e627785 is starting a new election at term 83
2018-10-24 13:40:38.140850 I | raft: 8b0591e77e627785 became candidate at term 84
2018-10-24 13:40:38.140921 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 84
2018-10-24 13:40:38.140993 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to f3246e3c0671bbf8 at term 84
2018-10-24 13:40:38.141013 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to 360e47b7f2484e5e at term 84
2018-10-24 13:40:39.173820 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context deadline exceeded" took too long (5.0005791s) to execute
2018-10-24 13:40:39.440654 I | raft: 8b0591e77e627785 is starting a new election at term 84
2018-10-24 13:40:39.440710 I | raft: 8b0591e77e627785 became candidate at term 85
2018-10-24 13:40:39.440723 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 85
2018-10-24 13:40:39.440740 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to f3246e3c0671bbf8 at term 85
2018-10-24 13:40:39.440757 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to 360e47b7f2484e5e at term 85
2018-10-24 13:40:40.740653 I | raft: 8b0591e77e627785 is starting a new election at term 85
2018-10-24 13:40:40.740707 I | raft: 8b0591e77e627785 became candidate at term 86
2018-10-24 13:40:40.740743 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 86
2018-10-24 13:40:40.740769 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to f3246e3c0671bbf8 at term 86
2018-10-24 13:40:40.740805 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to 360e47b7f2484e5e at term 86
2018-10-24 13:40:41.946425 W | etcdserver: timed out waiting for read index response
2018-10-24 13:40:42.140656 I | raft: 8b0591e77e627785 is starting a new election at term 86
2018-10-24 13:40:42.140705 I | raft: 8b0591e77e627785 became candidate at term 87
2018-10-24 13:40:42.140723 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 87
2018-10-24 13:40:42.140735 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to f3246e3c0671bbf8 at term 87
2018-10-24 13:40:42.140747 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to 360e47b7f2484e5e at term 87
2018-10-24 13:40:44.040675 I | raft: 8b0591e77e627785 is starting a new election at term 87
2018-10-24 13:40:44.040738 I | raft: 8b0591e77e627785 became candidate at term 88
2018-10-24 13:40:44.040760 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 88
2018-10-24 13:40:44.040780 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to f3246e3c0671bbf8 at term 88
2018-10-24 13:40:44.040801 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to 360e47b7f2484e5e at term 88
2018-10-24 13:40:44.244195 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context deadline exceeded" took too long (4.999173384s) to execute
2018-10-24 13:40:45.940721 I | raft: 8b0591e77e627785 is starting a new election at term 88
2018-10-24 13:40:45.940792 I | raft: 8b0591e77e627785 became candidate at term 89
2018-10-24 13:40:45.940810 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 89
2018-10-24 13:40:45.940827 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to f3246e3c0671bbf8 at term 89
2018-10-24 13:40:45.940842 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to 360e47b7f2484e5e at term 89
2018-10-24 13:40:47.640753 I | raft: 8b0591e77e627785 is starting a new election at term 89
2018-10-24 13:40:47.640828 I | raft: 8b0591e77e627785 became candidate at term 90
2018-10-24 13:40:47.640847 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 90
2018-10-24 13:40:47.640896 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to f3246e3c0671bbf8 at term 90
2018-10-24 13:40:47.640924 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to 360e47b7f2484e5e at term 90
2018-10-24 13:40:48.946750 W | etcdserver: timed out waiting for read index response
2018-10-24 13:40:49.298413 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context deadline exceeded" took too long (4.998843193s) to execute
2018-10-24 13:40:49.440717 I | raft: 8b0591e77e627785 is starting a new election at term 90
2018-10-24 13:40:49.440792 I | raft: 8b0591e77e627785 became candidate at term 91
2018-10-24 13:40:49.440810 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 91
2018-10-24 13:40:49.440825 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to f3246e3c0671bbf8 at term 91
2018-10-24 13:40:49.440837 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to 360e47b7f2484e5e at term 91
2018-10-24 13:40:50.942363 I | raft: 8b0591e77e627785 is starting a new election at term 91
2018-10-24 13:40:50.942414 I | raft: 8b0591e77e627785 became candidate at term 92
2018-10-24 13:40:50.942431 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 92
2018-10-24 13:40:50.942449 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to f3246e3c0671bbf8 at term 92
2018-10-24 13:40:50.942464 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to 360e47b7f2484e5e at term 92
2018-10-24 13:40:51.867966 I | rafthttp: peer f3246e3c0671bbf8 became active
2018-10-24 13:40:51.867999 I | rafthttp: established a TCP streaming connection with peer f3246e3c0671bbf8 (stream MsgApp v2 reader)
2018-10-24 13:40:51.940665 I | raft: 8b0591e77e627785 is starting a new election at term 92
2018-10-24 13:40:51.940723 I | raft: 8b0591e77e627785 became candidate at term 93
2018-10-24 13:40:51.940743 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 93
2018-10-24 13:40:51.940761 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to f3246e3c0671bbf8 at term 93
2018-10-24 13:40:51.940781 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to 360e47b7f2484e5e at term 93
2018-10-24 13:40:53.640776 I | raft: 8b0591e77e627785 is starting a new election at term 93
2018-10-24 13:40:53.640818 I | raft: 8b0591e77e627785 became candidate at term 94
2018-10-24 13:40:53.640833 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 94
2018-10-24 13:40:53.640845 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to 360e47b7f2484e5e at term 94
2018-10-24 13:40:53.640855 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to f3246e3c0671bbf8 at term 94
2018-10-24 13:40:53.685994 I | rafthttp: established a TCP streaming connection with peer f3246e3c0671bbf8 (stream Message reader)
2018-10-24 13:40:54.030090 I | raft: 8b0591e77e627785 [term: 94] ignored a MsgVote message with lower term from f3246e3c0671bbf8 [term: 81]
2018-10-24 13:40:54.364544 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context canceled" took too long (5.00639698s) to execute
WARNING: 2018/10/24 13:40:54 grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"
2018-10-24 13:40:54.640744 I | raft: 8b0591e77e627785 is starting a new election at term 94
2018-10-24 13:40:54.640826 I | raft: 8b0591e77e627785 became candidate at term 95
2018-10-24 13:40:54.640852 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 95
2018-10-24 13:40:54.640902 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to f3246e3c0671bbf8 at term 95
2018-10-24 13:40:54.640937 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to 360e47b7f2484e5e at term 95
2018-10-24 13:40:55.947194 W | etcdserver: timed out waiting for read index response
2018-10-24 13:40:56.340654 I | raft: 8b0591e77e627785 is starting a new election at term 95
2018-10-24 13:40:56.340736 I | raft: 8b0591e77e627785 became candidate at term 96
2018-10-24 13:40:56.340754 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 96
2018-10-24 13:40:56.340768 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to f3246e3c0671bbf8 at term 96
2018-10-24 13:40:56.340779 I | raft: 8b0591e77e627785 [logterm: 80, index: 662] sent MsgVote request to 360e47b7f2484e5e at term 96
2018-10-24 13:40:56.707817 I | raft: 8b0591e77e627785 [term: 96] ignored a MsgVoteResp message with lower term from f3246e3c0671bbf8 [term: 95]
2018-10-24 13:40:56.707894 I | raft: 8b0591e77e627785 received MsgVoteResp from f3246e3c0671bbf8 at term 96
2018-10-24 13:40:56.707913 I | raft: 8b0591e77e627785 [quorum:2] has received 2 MsgVoteResp votes and 0 vote rejections
2018-10-24 13:40:56.707945 I | raft: 8b0591e77e627785 became leader at term 96
2018-10-24 13:40:56.707965 I | raft: raft.node: 8b0591e77e627785 elected leader 8b0591e77e627785 at term 96
2018-10-24 13:40:59.443437 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context canceled" took too long (4.999651703s) to execute
WARNING: 2018/10/24 13:40:59 grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"
2018-10-24 13:41:01.412468 W | etcdserver: failed to send out heartbeat on time (exceeded the 100ms timeout for 371.635915ms)
2018-10-24 13:41:01.412554 W | etcdserver: server is likely overloaded
2018-10-24 13:41:01.412570 W | etcdserver: failed to send out heartbeat on time (exceeded the 100ms timeout for 371.754263ms)
2018-10-24 13:41:01.412579 W | etcdserver: server is likely overloaded
2018-10-24 13:41:02.887554 W | etcdserver: failed to send out heartbeat on time (exceeded the 100ms timeout for 46.865907ms)
2018-10-24 13:41:02.887595 W | etcdserver: server is likely overloaded
2018-10-24 13:41:02.887607 W | etcdserver: failed to send out heartbeat on time (exceeded the 100ms timeout for 46.926441ms)
2018-10-24 13:41:02.887614 W | etcdserver: server is likely overloaded
2018-10-24 13:41:02.947409 W | etcdserver: timed out waiting for read index response
2018-10-24 13:41:03.505125 W | etcdserver: read-only range request "key:\"foo\" " with result "range_response_count:0 size:5" took too long (3.989325249s) to execute
2018-10-24 13:41:05.140673 W | raft: 8b0591e77e627785 stepped down to follower since quorum is not active
2018-10-24 13:41:05.140735 I | raft: 8b0591e77e627785 became follower at term 96
2018-10-24 13:41:05.140750 I | raft: raft.node: 8b0591e77e627785 lost leader 8b0591e77e627785 at term 96
2018-10-24 13:41:06.640746 I | raft: 8b0591e77e627785 is starting a new election at term 96
2018-10-24 13:41:06.640808 I | raft: 8b0591e77e627785 became candidate at term 97
2018-10-24 13:41:06.640823 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 97
2018-10-24 13:41:06.640835 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to f3246e3c0671bbf8 at term 97
2018-10-24 13:41:06.640846 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to 360e47b7f2484e5e at term 97
2018-10-24 13:41:08.040654 I | raft: 8b0591e77e627785 is starting a new election at term 97
2018-10-24 13:41:08.040719 I | raft: 8b0591e77e627785 became candidate at term 98
2018-10-24 13:41:08.040737 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 98
2018-10-24 13:41:08.040753 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to f3246e3c0671bbf8 at term 98
2018-10-24 13:41:08.040768 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to 360e47b7f2484e5e at term 98
2018-10-24 13:41:08.762551 W | rafthttp: lost the TCP streaming connection with peer f3246e3c0671bbf8 (stream MsgApp v2 reader)
2018-10-24 13:41:08.762620 E | rafthttp: failed to read f3246e3c0671bbf8 on stream MsgApp v2 (read tcp 10.233.66.5:43016->10.233.65.4:2380: i/o timeout)
2018-10-24 13:41:08.762631 I | rafthttp: peer f3246e3c0671bbf8 became inactive
2018-10-24 13:41:08.954408 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context canceled" took too long (4.999195785s) to execute
WARNING: 2018/10/24 13:41:08 grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"
2018-10-24 13:41:09.440661 I | raft: 8b0591e77e627785 is starting a new election at term 98
2018-10-24 13:41:09.440738 I | raft: 8b0591e77e627785 became candidate at term 99
2018-10-24 13:41:09.440758 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 99
2018-10-24 13:41:09.440781 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to f3246e3c0671bbf8 at term 99
2018-10-24 13:41:09.440798 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to 360e47b7f2484e5e at term 99
2018-10-24 13:41:10.520272 W | rafthttp: lost the TCP streaming connection with peer f3246e3c0671bbf8 (stream Message reader)
2018-10-24 13:41:10.955368 W | etcdserver: timed out waiting for read index response
2018-10-24 13:41:11.040711 I | raft: 8b0591e77e627785 is starting a new election at term 99
2018-10-24 13:41:11.040772 I | raft: 8b0591e77e627785 became candidate at term 100
2018-10-24 13:41:11.040790 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 100
2018-10-24 13:41:11.040806 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to f3246e3c0671bbf8 at term 100
2018-10-24 13:41:11.040820 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to 360e47b7f2484e5e at term 100
2018-10-24 13:41:12.040852 I | raft: 8b0591e77e627785 is starting a new election at term 100
2018-10-24 13:41:12.041018 I | raft: 8b0591e77e627785 became candidate at term 101
2018-10-24 13:41:12.041040 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 101
2018-10-24 13:41:12.041057 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to f3246e3c0671bbf8 at term 101
2018-10-24 13:41:12.041085 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to 360e47b7f2484e5e at term 101
2018-10-24 13:41:13.240679 I | raft: 8b0591e77e627785 is starting a new election at term 101
2018-10-24 13:41:13.240760 I | raft: 8b0591e77e627785 became candidate at term 102
2018-10-24 13:41:13.240783 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 102
2018-10-24 13:41:13.240802 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to f3246e3c0671bbf8 at term 102
2018-10-24 13:41:13.240820 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to 360e47b7f2484e5e at term 102
2018-10-24 13:41:14.017303 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context canceled" took too long (4.999298102s) to execute
WARNING: 2018/10/24 13:41:14 grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"
2018-10-24 13:41:14.340667 I | raft: 8b0591e77e627785 is starting a new election at term 102
2018-10-24 13:41:14.340722 I | raft: 8b0591e77e627785 became candidate at term 103
2018-10-24 13:41:14.340734 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 103
2018-10-24 13:41:14.340747 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to f3246e3c0671bbf8 at term 103
2018-10-24 13:41:14.340757 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to 360e47b7f2484e5e at term 103
2018-10-24 13:41:15.340597 I | raft: 8b0591e77e627785 is starting a new election at term 103
2018-10-24 13:41:15.340654 I | raft: 8b0591e77e627785 became candidate at term 104
2018-10-24 13:41:15.340667 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 104
2018-10-24 13:41:15.340680 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to f3246e3c0671bbf8 at term 104
2018-10-24 13:41:15.340694 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to 360e47b7f2484e5e at term 104
2018-10-24 13:41:17.440682 I | raft: 8b0591e77e627785 is starting a new election at term 104
2018-10-24 13:41:17.440746 I | raft: 8b0591e77e627785 became candidate at term 105
2018-10-24 13:41:17.440765 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 105
2018-10-24 13:41:17.440781 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to f3246e3c0671bbf8 at term 105
2018-10-24 13:41:17.440814 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to 360e47b7f2484e5e at term 105
2018-10-24 13:41:17.955609 W | etcdserver: timed out waiting for read index response
2018-10-24 13:41:19.040698 I | raft: 8b0591e77e627785 is starting a new election at term 105
2018-10-24 13:41:19.040766 I | raft: 8b0591e77e627785 became candidate at term 106
2018-10-24 13:41:19.040791 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 106
2018-10-24 13:41:19.040811 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to f3246e3c0671bbf8 at term 106
2018-10-24 13:41:19.040837 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to 360e47b7f2484e5e at term 106
2018-10-24 13:41:19.086880 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context deadline exceeded" took too long (4.998605677s) to execute
2018-10-24 13:41:20.437662 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context deadline exceeded" took too long (4.998872914s) to execute
2018-10-24 13:41:20.445474 N | pkg/osutil: received terminated signal, shutting down...
2018-10-24 13:41:20.445904 I | etcdserver: skipped leadership transfer for stopping non-leader member
2018-10-24 13:41:20.446007 W | etcdserver: read-only range request "key:\"foo\" " with result "error:context canceled" took too long (1.307936472s) to execute
WARNING: 2018/10/24 13:41:20 grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"
2018-10-24 13:41:20.940701 I | raft: 8b0591e77e627785 is starting a new election at term 106
2018-10-24 13:41:20.940763 I | raft: 8b0591e77e627785 became candidate at term 107
2018-10-24 13:41:20.940796 I | raft: 8b0591e77e627785 received MsgVoteResp from 8b0591e77e627785 at term 107
2018-10-24 13:41:20.940811 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to f3246e3c0671bbf8 at term 107
2018-10-24 13:41:20.940823 I | raft: 8b0591e77e627785 [logterm: 96, index: 667] sent MsgVote request to 360e47b7f2484e5e at term 107
2018-10-24 13:41:26.406287 I | rafthttp: peer f3246e3c0671bbf8 became active
2018-10-24 13:41:26.406332 I | rafthttp: established a TCP streaming connection with peer f3246e3c0671bbf8 (stream MsgApp v2 reader)
2018-10-24 13:41:26.818595 E | rafthttp: failed to dial f3246e3c0671bbf8 on stream Message (read tcp 10.233.66.5:43100->10.233.65.4:2380: i/o timeout)
2018-10-24 13:41:26.818648 I | rafthttp: peer f3246e3c0671bbf8 became inactive
2018-10-24 13:41:31.406695 W | rafthttp: lost the TCP streaming connection with peer f3246e3c0671bbf8 (stream MsgApp v2 reader)
2018-10-24 13:41:45.118692 I | rafthttp: peer f3246e3c0671bbf8 became active
2018-10-24 13:41:45.118732 I | rafthttp: established a TCP streaming connection with peer f3246e3c0671bbf8 (stream MsgApp v2 reader)
2018-10-24 13:41:45.119014 I | rafthttp: established a TCP streaming connection with peer f3246e3c0671bbf8 (stream Message reader)
2018-10-24 13:41:45.125744 W | rafthttp: lost the TCP streaming connection with peer f3246e3c0671bbf8 (stream Message reader)
2018-10-24 13:41:45.127364 W | rafthttp: lost the TCP streaming connection with peer f3246e3c06

@rmadaka
Copy link
Author

rmadaka commented Oct 25, 2018

This Logs for ETCD pod which is in completed state:

2018-10-24 10:18:56.510531 I | raft: 4c6267e9f13aa2f7 became follower at term 103
2018-10-24 10:18:56.510552 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 103
2018-10-24 10:18:56.510585 I | raft: 4c6267e9f13aa2f7 [term: 103] received a MsgVote message with higher term from f91b7b5a837d265d [term: 106]
2018-10-24 10:18:56.510603 I | raft: 4c6267e9f13aa2f7 became follower at term 106
2018-10-24 10:18:56.510625 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 106
2018-10-24 10:18:56.510642 I | raft: 4c6267e9f13aa2f7 [term: 106] received a MsgVote message with higher term from f91b7b5a837d265d [term: 108]
2018-10-24 10:18:56.510659 I | raft: 4c6267e9f13aa2f7 became follower at term 108
2018-10-24 10:18:56.510681 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 108
2018-10-24 10:18:56.510713 I | raft: 4c6267e9f13aa2f7 [term: 108] received a MsgVote message with higher term from f91b7b5a837d265d [term: 109]
2018-10-24 10:18:56.510731 I | raft: 4c6267e9f13aa2f7 became follower at term 109
2018-10-24 10:18:56.511166 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 109
2018-10-24 10:18:56.511204 I | raft: 4c6267e9f13aa2f7 [term: 109] received a MsgVote message with higher term from f91b7b5a837d265d [term: 110]
2018-10-24 10:18:56.511226 I | raft: 4c6267e9f13aa2f7 became follower at term 110
2018-10-24 10:18:56.511248 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 110
2018-10-24 10:18:56.511323 I | raft: 4c6267e9f13aa2f7 [term: 110] received a MsgVote message with higher term from f91b7b5a837d265d [term: 111]
2018-10-24 10:18:56.511350 I | raft: 4c6267e9f13aa2f7 became follower at term 111
2018-10-24 10:18:56.511393 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 111
2018-10-24 10:18:56.511455 I | raft: 4c6267e9f13aa2f7 [term: 111] received a MsgVote message with higher term from f91b7b5a837d265d [term: 112]
2018-10-24 10:18:56.511475 I | raft: 4c6267e9f13aa2f7 became follower at term 112
2018-10-24 10:18:56.511497 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 112
2018-10-24 10:18:56.511531 I | raft: 4c6267e9f13aa2f7 [term: 112] received a MsgVote message with higher term from f91b7b5a837d265d [term: 113]
2018-10-24 10:18:56.511550 I | raft: 4c6267e9f13aa2f7 became follower at term 113
2018-10-24 10:18:56.511571 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 113
2018-10-24 10:18:56.511588 I | raft: 4c6267e9f13aa2f7 [term: 113] received a MsgVote message with higher term from f91b7b5a837d265d [term: 115]
2018-10-24 10:18:56.511605 I | raft: 4c6267e9f13aa2f7 became follower at term 115
2018-10-24 10:18:56.511627 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 115
2018-10-24 10:18:56.511660 I | raft: 4c6267e9f13aa2f7 [term: 115] received a MsgVote message with higher term from f91b7b5a837d265d [term: 116]
2018-10-24 10:18:56.511679 I | raft: 4c6267e9f13aa2f7 became follower at term 116
2018-10-24 10:18:56.511701 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 116
2018-10-24 10:18:56.511717 I | raft: 4c6267e9f13aa2f7 [term: 116] received a MsgVote message with higher term from f91b7b5a837d265d [term: 120]
2018-10-24 10:18:56.511734 I | raft: 4c6267e9f13aa2f7 became follower at term 120
2018-10-24 10:18:56.512914 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 120
2018-10-24 10:18:56.512980 I | raft: 4c6267e9f13aa2f7 [term: 120] received a MsgVote message with higher term from f91b7b5a837d265d [term: 121]
2018-10-24 10:18:56.513004 I | raft: 4c6267e9f13aa2f7 became follower at term 121
2018-10-24 10:18:56.513027 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 121
2018-10-24 10:18:56.513044 I | raft: 4c6267e9f13aa2f7 [term: 121] received a MsgVote message with higher term from f91b7b5a837d265d [term: 123]
2018-10-24 10:18:56.513063 I | raft: 4c6267e9f13aa2f7 became follower at term 123
2018-10-24 10:18:56.513085 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 123
2018-10-24 10:18:56.513117 I | raft: 4c6267e9f13aa2f7 [term: 123] received a MsgVote message with higher term from f91b7b5a837d265d [term: 125]
2018-10-24 10:18:56.513146 I | raft: 4c6267e9f13aa2f7 became follower at term 125
2018-10-24 10:18:56.513168 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 125
2018-10-24 10:18:56.513185 I | raft: 4c6267e9f13aa2f7 [term: 125] received a MsgVote message with higher term from f91b7b5a837d265d [term: 127]
2018-10-24 10:18:56.513203 I | raft: 4c6267e9f13aa2f7 became follower at term 127
2018-10-24 10:18:56.513224 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 127
2018-10-24 10:18:56.513256 I | raft: 4c6267e9f13aa2f7 [term: 127] received a MsgVote message with higher term from f91b7b5a837d265d [term: 129]
2018-10-24 10:18:56.513274 I | raft: 4c6267e9f13aa2f7 became follower at term 129
2018-10-24 10:18:56.513296 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 129
2018-10-24 10:18:56.513312 I | raft: 4c6267e9f13aa2f7 [term: 129] received a MsgVote message with higher term from f91b7b5a837d265d [term: 130]
2018-10-24 10:18:56.513330 I | raft: 4c6267e9f13aa2f7 became follower at term 130
2018-10-24 10:18:56.513351 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 130
2018-10-24 10:18:56.513382 I | raft: 4c6267e9f13aa2f7 [term: 130] received a MsgVote message with higher term from f91b7b5a837d265d [term: 131]
2018-10-24 10:18:56.513401 I | raft: 4c6267e9f13aa2f7 became follower at term 131
2018-10-24 10:18:56.513422 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 131
2018-10-24 10:18:56.513438 I | raft: 4c6267e9f13aa2f7 [term: 131] received a MsgVote message with higher term from f91b7b5a837d265d [term: 132]
2018-10-24 10:18:56.513456 I | raft: 4c6267e9f13aa2f7 became follower at term 132
2018-10-24 10:18:56.513478 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 132
2018-10-24 10:18:56.513509 I | raft: 4c6267e9f13aa2f7 [term: 132] received a MsgVote message with higher term from f91b7b5a837d265d [term: 135]
2018-10-24 10:18:56.513527 I | raft: 4c6267e9f13aa2f7 became follower at term 135
2018-10-24 10:18:56.513548 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 135
2018-10-24 10:18:56.513564 I | raft: 4c6267e9f13aa2f7 [term: 135] received a MsgVote message with higher term from f91b7b5a837d265d [term: 136]
2018-10-24 10:18:56.513582 I | raft: 4c6267e9f13aa2f7 became follower at term 136
2018-10-24 10:18:56.513603 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 136
2018-10-24 10:18:56.513717 I | raft: 4c6267e9f13aa2f7 [term: 136] received a MsgVote message with higher term from f91b7b5a837d265d [term: 137]
2018-10-24 10:18:56.513742 I | raft: 4c6267e9f13aa2f7 became follower at term 137
2018-10-24 10:18:56.513998 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 137
2018-10-24 10:18:56.514021 I | raft: 4c6267e9f13aa2f7 [term: 137] received a MsgVote message with higher term from f91b7b5a837d265d [term: 140]
2018-10-24 10:18:56.514052 I | raft: 4c6267e9f13aa2f7 became follower at term 140
2018-10-24 10:18:56.514082 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 140
2018-10-24 10:18:56.514118 I | raft: 4c6267e9f13aa2f7 [term: 140] received a MsgVote message with higher term from f91b7b5a837d265d [term: 141]
2018-10-24 10:18:56.514150 I | raft: 4c6267e9f13aa2f7 became follower at term 141
2018-10-24 10:18:56.514173 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 141
2018-10-24 10:18:56.514190 I | raft: 4c6267e9f13aa2f7 [term: 141] received a MsgVote message with higher term from f91b7b5a837d265d [term: 142]
2018-10-24 10:18:56.514208 I | raft: 4c6267e9f13aa2f7 became follower at term 142
2018-10-24 10:18:56.514230 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 142
2018-10-24 10:18:56.514262 I | raft: 4c6267e9f13aa2f7 [term: 142] received a MsgVote message with higher term from f91b7b5a837d265d [term: 143]
2018-10-24 10:18:56.514280 I | raft: 4c6267e9f13aa2f7 became follower at term 143
2018-10-24 10:18:56.514302 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 143
2018-10-24 10:18:56.514318 I | raft: 4c6267e9f13aa2f7 [term: 143] received a MsgVote message with higher term from f91b7b5a837d265d [term: 144]
2018-10-24 10:18:56.514335 I | raft: 4c6267e9f13aa2f7 became follower at term 144
2018-10-24 10:18:56.514357 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 144
2018-10-24 10:18:56.514388 I | raft: 4c6267e9f13aa2f7 [term: 144] received a MsgVote message with higher term from f91b7b5a837d265d [term: 146]
2018-10-24 10:18:56.514428 I | raft: 4c6267e9f13aa2f7 became follower at term 146
2018-10-24 10:18:56.514452 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 146
2018-10-24 10:18:56.514470 I | raft: 4c6267e9f13aa2f7 [term: 146] received a MsgVote message with higher term from f91b7b5a837d265d [term: 153]
2018-10-24 10:18:56.514487 I | raft: 4c6267e9f13aa2f7 became follower at term 153
2018-10-24 10:18:56.514509 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 153
2018-10-24 10:18:56.514548 I | raft: 4c6267e9f13aa2f7 [term: 153] received a MsgVote message with higher term from f91b7b5a837d265d [term: 154]
2018-10-24 10:18:56.514567 I | raft: 4c6267e9f13aa2f7 became follower at term 154
2018-10-24 10:18:56.514589 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 154
2018-10-24 10:18:56.514605 I | raft: 4c6267e9f13aa2f7 [term: 154] received a MsgVote message with higher term from f91b7b5a837d265d [term: 156]
2018-10-24 10:18:56.514623 I | raft: 4c6267e9f13aa2f7 became follower at term 156
2018-10-24 10:18:56.514644 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 156
2018-10-24 10:18:56.514676 I | raft: 4c6267e9f13aa2f7 [term: 156] received a MsgVote message with higher term from f91b7b5a837d265d [term: 157]
2018-10-24 10:18:56.514694 I | raft: 4c6267e9f13aa2f7 became follower at term 157
2018-10-24 10:18:56.514719 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 157
2018-10-24 10:18:56.514737 I | raft: 4c6267e9f13aa2f7 [term: 157] received a MsgVote message with higher term from f91b7b5a837d265d [term: 159]
2018-10-24 10:18:56.514862 I | raft: 4c6267e9f13aa2f7 became follower at term 159
2018-10-24 10:18:56.514909 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 159
2018-10-24 10:18:56.514944 I | raft: 4c6267e9f13aa2f7 [term: 159] received a MsgVote message with higher term from f91b7b5a837d265d [term: 161]
2018-10-24 10:18:56.514965 I | raft: 4c6267e9f13aa2f7 became follower at term 161
2018-10-24 10:18:56.514987 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for f91b7b5a837d265d [logterm: 47, index: 166] at term 161
2018-10-24 10:18:56.515022 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 89]
2018-10-24 10:18:56.515038 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 90]
2018-10-24 10:18:56.515068 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 91]
2018-10-24 10:18:56.515083 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 93]
2018-10-24 10:18:56.515112 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 95]
2018-10-24 10:18:56.515138 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 97]
2018-10-24 10:18:56.515170 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 98]
2018-10-24 10:18:56.515186 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 99]
2018-10-24 10:18:56.515215 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 102]
2018-10-24 10:18:56.515231 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 104]
2018-10-24 10:18:56.515260 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 105]
2018-10-24 10:18:56.515275 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 106]
2018-10-24 10:18:56.515305 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 107]
2018-10-24 10:18:56.515320 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 114]
2018-10-24 10:18:56.515349 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 117]
2018-10-24 10:18:56.515364 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 118]
2018-10-24 10:18:56.515393 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 119]
2018-10-24 10:18:56.515408 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 120]
2018-10-24 10:18:56.515438 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 122]
2018-10-24 10:18:56.515453 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 124]
2018-10-24 10:18:56.515482 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 126]
2018-10-24 10:18:56.515497 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 128]
2018-10-24 10:18:56.515526 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 133]
2018-10-24 10:18:56.515542 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 134]
2018-10-24 10:18:56.515571 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 135]
2018-10-24 10:18:56.515589 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 138]
2018-10-24 10:18:56.515618 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 139]
2018-10-24 10:18:56.515634 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 141]
2018-10-24 10:18:56.515663 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 145]
2018-10-24 10:18:56.515678 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 147]
2018-10-24 10:18:56.515707 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 148]
2018-10-24 10:18:56.515723 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 149]
2018-10-24 10:18:56.604896 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:18:56.858668 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:18:56.930555 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:56.930629 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:56.930853 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:18:56.930865 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:18:57.049916 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:18:57.049987 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:18:57.058973 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:18:57.059008 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:18:57.061059 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:18:57.061077 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:18:57.300853 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 150]
2018-10-24 10:18:57.466313 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 151]
2018-10-24 10:18:57.466839 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:57.466864 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:57.467337 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:57.467355 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:57.467732 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:57.474861 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:57.475241 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:57.475252 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:57.475603 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:57.475615 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:57.719566 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:18:57.720306 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:18:57.985556 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:18:58.096560 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:18:58.096671 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:18:58.097331 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.097366 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.097739 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.103032 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.103593 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.103612 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.109355 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.109395 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.109715 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.109725 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.112092 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.112188 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.113424 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.113693 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.114059 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.114070 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.114407 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.114427 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.115188 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.115202 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.115586 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.115596 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:58.171743 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:18:58.196974 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 152]
2018-10-24 10:18:58.212862 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:18:58.212930 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:18:58.280435 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:18:59.087528 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:59.550669 E | rafthttp: failed to dial f91b7b5a837d265d on stream Message (dial tcp 10.233.66.4:2380: i/o timeout)
2018-10-24 10:18:59.550743 I | rafthttp: peer f91b7b5a837d265d became inactive
2018-10-24 10:18:59.595644 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:18:59.742441 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 154]
2018-10-24 10:19:01.269092 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:01.293053 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:02.800275 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 155]
2018-10-24 10:19:02.937223 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:03.192095 W | rafthttp: health check for peer 14ef5a1bb6b7a26e could not connect: dial tcp [fe80::b0a2:faff:fe12:8ada]:2380: connect: invalid argument
2018-10-24 10:19:32.337516 I | rafthttp: peer f91b7b5a837d265d became active
2018-10-24 10:19:32.337601 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.337612 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.351035 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.351071 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.351517 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.351527 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.355608 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:32.355637 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:32.362943 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:32.362969 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:32.363438 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:32.363448 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:32.365674 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:32.365707 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:32.368730 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:32.368911 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:32.369708 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:32.369724 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:32.379705 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.379733 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.381159 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.381175 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.384231 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.384293 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.423980 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:19:32.424015 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:19:32.446405 E | rafthttp: failed to dial f91b7b5a837d265d on stream MsgApp v2 (dial tcp 10.233.66.4:2380: i/o timeout)
2018-10-24 10:19:32.446437 I | rafthttp: peer f91b7b5a837d265d became inactive
2018-10-24 10:19:32.462133 W | rafthttp: health check for peer 14ef5a1bb6b7a26e could not connect: dial tcp [fe80::b0a2:faff:fe12:8ada]:2380: connect: invalid argument
2018-10-24 10:19:32.462195 W | rafthttp: the clock difference against peer be72e21dcb4948d0 is too high [3.456370547s > 1s]
2018-10-24 10:19:32.462218 W | rafthttp: health check for peer f91b7b5a837d265d could not connect: dial tcp: i/o timeout
2018-10-24 10:19:32.464596 W | rafthttp: lost the TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 reader)
2018-10-24 10:19:32.496919 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 158]
2018-10-24 10:19:32.496962 I | raft: 4c6267e9f13aa2f7 [term: 161] ignored a MsgVote message with lower term from be72e21dcb4948d0 [term: 160]
2018-10-24 10:19:32.496997 I | raft: 4c6267e9f13aa2f7 [term: 161] received a MsgVote message with higher term from be72e21dcb4948d0 [term: 162]
2018-10-24 10:19:32.497046 I | raft: 4c6267e9f13aa2f7 became follower at term 162
2018-10-24 10:19:32.497111 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for be72e21dcb4948d0 [logterm: 47, index: 166] at term 162
2018-10-24 10:19:32.497146 I | raft: 4c6267e9f13aa2f7 [term: 162] received a MsgVote message with higher term from be72e21dcb4948d0 [term: 163]
2018-10-24 10:19:32.497166 I | raft: 4c6267e9f13aa2f7 became follower at term 163
2018-10-24 10:19:32.497187 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for be72e21dcb4948d0 [logterm: 47, index: 166] at term 163
WARNING: 2018/10/24 10:19:32 grpc: Server.processUnaryRPC failed to write status connection error: desc = "transport is closing"
2018-10-24 10:19:32.508398 W | rafthttp: lost the TCP streaming connection with peer be72e21dcb4948d0 (stream Message reader)
2018-10-24 10:19:32.516521 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:32.516544 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:32.527926 I | rafthttp: peer f91b7b5a837d265d became active
2018-10-24 10:19:32.527951 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.527958 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.528412 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.528422 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.530173 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.530197 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.530644 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.530654 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.531338 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.531353 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.538904 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.538928 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.539378 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.539391 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.540096 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.540114 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.540546 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.540556 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.588560 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:19:32.588600 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:19:32.591543 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.591560 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.592061 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.592078 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.592399 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.592409 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.592741 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.593900 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.594329 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.594354 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.594740 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.594960 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.595355 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.595369 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.595743 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.595860 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:32.599109 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.599139 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.602206 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.602227 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.602663 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.602673 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.603460 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.603478 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.616081 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.616116 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.627422 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.627463 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.636112 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:19:32.636149 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:19:32.636466 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:19:32.636475 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:19:32.638990 I | raft: 4c6267e9f13aa2f7 [term: 163] received a MsgVote message with higher term from be72e21dcb4948d0 [term: 164]
2018-10-24 10:19:32.639018 I | raft: 4c6267e9f13aa2f7 became follower at term 164
2018-10-24 10:19:32.639030 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for be72e21dcb4948d0 [logterm: 47, index: 166] at term 164
2018-10-24 10:19:32.639042 I | raft: 4c6267e9f13aa2f7 [term: 164] received a MsgVote message with higher term from be72e21dcb4948d0 [term: 165]
2018-10-24 10:19:32.639050 I | raft: 4c6267e9f13aa2f7 became follower at term 165
2018-10-24 10:19:32.639071 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for be72e21dcb4948d0 [logterm: 47, index: 166] at term 165
2018-10-24 10:19:32.639085 I | raft: 4c6267e9f13aa2f7 [term: 165] received a MsgVote message with higher term from be72e21dcb4948d0 [term: 166]
2018-10-24 10:19:32.639097 I | raft: 4c6267e9f13aa2f7 became follower at term 166
2018-10-24 10:19:32.639106 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for be72e21dcb4948d0 [logterm: 47, index: 166] at term 166
2018-10-24 10:19:32.639116 I | raft: 4c6267e9f13aa2f7 [term: 166] received a MsgVote message with higher term from be72e21dcb4948d0 [term: 167]
2018-10-24 10:19:32.639137 I | raft: 4c6267e9f13aa2f7 became follower at term 167
2018-10-24 10:19:32.639146 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for be72e21dcb4948d0 [logterm: 47, index: 166] at term 167
2018-10-24 10:19:32.639158 I | raft: 4c6267e9f13aa2f7 [term: 167] received a MsgVote message with higher term from be72e21dcb4948d0 [term: 168]
2018-10-24 10:19:32.639170 I | raft: 4c6267e9f13aa2f7 became follower at term 168
2018-10-24 10:19:32.639178 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for be72e21dcb4948d0 [logterm: 47, index: 166] at term 168
2018-10-24 10:19:32.639188 I | raft: 4c6267e9f13aa2f7 [term: 168] received a MsgVote message with higher term from be72e21dcb4948d0 [term: 169]
2018-10-24 10:19:32.639199 I | raft: 4c6267e9f13aa2f7 became follower at term 169
2018-10-24 10:19:32.639207 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for be72e21dcb4948d0 [logterm: 47, index: 166] at term 169
2018-10-24 10:19:32.639219 I | raft: 4c6267e9f13aa2f7 [term: 169] received a MsgVote message with higher term from be72e21dcb4948d0 [term: 170]
2018-10-24 10:19:32.639239 I | raft: 4c6267e9f13aa2f7 became follower at term 170
2018-10-24 10:19:32.639247 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for be72e21dcb4948d0 [logterm: 47, index: 166] at term 170
2018-10-24 10:19:32.639257 I | raft: 4c6267e9f13aa2f7 [term: 170] received a MsgVote message with higher term from be72e21dcb4948d0 [term: 171]
2018-10-24 10:19:32.639265 I | raft: 4c6267e9f13aa2f7 became follower at term 171
2018-10-24 10:19:32.639273 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for be72e21dcb4948d0 [logterm: 47, index: 166] at term 171
2018-10-24 10:19:32.639287 I | raft: 4c6267e9f13aa2f7 [term: 171] received a MsgVote message with higher term from be72e21dcb4948d0 [term: 172]
2018-10-24 10:19:32.639298 I | raft: 4c6267e9f13aa2f7 became follower at term 172
2018-10-24 10:19:32.639307 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for be72e21dcb4948d0 [logterm: 47, index: 166] at term 172
2018-10-24 10:19:32.639317 I | raft: 4c6267e9f13aa2f7 [term: 172] received a MsgVote message with higher term from be72e21dcb4948d0 [term: 173]
2018-10-24 10:19:32.639325 I | raft: 4c6267e9f13aa2f7 became follower at term 173
2018-10-24 10:19:32.639333 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for be72e21dcb4948d0 [logterm: 47, index: 166] at term 173
2018-10-24 10:19:32.639344 I | raft: 4c6267e9f13aa2f7 [term: 173] received a MsgVote message with higher term from be72e21dcb4948d0 [term: 174]
2018-10-24 10:19:32.639352 I | raft: 4c6267e9f13aa2f7 became follower at term 174
2018-10-24 10:19:32.639359 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for be72e21dcb4948d0 [logterm: 47, index: 166] at term 174
2018-10-24 10:19:32.639366 I | raft: 4c6267e9f13aa2f7 [term: 174] received a MsgVote message with higher term from be72e21dcb4948d0 [term: 175]
2018-10-24 10:19:32.639373 I | raft: 4c6267e9f13aa2f7 became follower at term 175
2018-10-24 10:19:32.639381 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for be72e21dcb4948d0 [logterm: 47, index: 166] at term 175
2018-10-24 10:19:32.639391 I | raft: 4c6267e9f13aa2f7 [term: 175] received a MsgVote message with higher term from be72e21dcb4948d0 [term: 176]
2018-10-24 10:19:32.639399 I | raft: 4c6267e9f13aa2f7 became follower at term 176
2018-10-24 10:19:32.639406 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166, vote: 0] cast MsgVote for be72e21dcb4948d0 [logterm: 47, index: 166] at term 176
2018-10-24 10:19:32.644113 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:32.644147 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:32.648061 W | rafthttp: closed an existing TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:32.648092 I | rafthttp: established a TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:32.658406 E | rafthttp: failed to dial f91b7b5a837d265d on stream Message (dial tcp: lookup etcd-spxbvfltfd.etcd.gcs.svc on 10.233.0.3:53: dial udp 10.233.0.3:53: i/o timeout)
2018-10-24 10:19:32.658434 I | rafthttp: peer f91b7b5a837d265d became inactive
2018-10-24 10:19:32.693595 I | rafthttp: peer f91b7b5a837d265d became active
2018-10-24 10:19:32.693636 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.693648 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.701282 W | rafthttp: closed an existing TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:32.701318 I | rafthttp: established a TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:33.791140 I | raft: 4c6267e9f13aa2f7 no leader at term 176; dropping index reading msg
2018-10-24 10:19:33.806930 I | raft: 4c6267e9f13aa2f7 is starting a new election at term 176
2018-10-24 10:19:33.806982 I | raft: 4c6267e9f13aa2f7 became candidate at term 177
2018-10-24 10:19:33.806998 I | raft: 4c6267e9f13aa2f7 received MsgVoteResp from 4c6267e9f13aa2f7 at term 177
2018-10-24 10:19:33.807015 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to be72e21dcb4948d0 at term 177
2018-10-24 10:19:33.807027 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to f91b7b5a837d265d at term 177
2018-10-24 10:19:33.807037 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to 14ef5a1bb6b7a26e at term 177
2018-10-24 10:19:34.465911 E | rafthttp: failed to dial be72e21dcb4948d0 on stream MsgApp v2 (dial tcp: lookup etcd-c2ljdps9hf.etcd.gcs.svc on 10.233.0.3:53: dial udp 10.233.0.3:53: i/o timeout)
2018-10-24 10:19:34.465953 I | rafthttp: peer be72e21dcb4948d0 became inactive
2018-10-24 10:19:34.600154 E | rafthttp: failed to dial f91b7b5a837d265d on stream MsgApp v2 (dial tcp 10.233.66.4:2380: i/o timeout)
2018-10-24 10:19:34.600195 I | rafthttp: peer f91b7b5a837d265d became inactive
2018-10-24 10:19:35.606235 I | raft: 4c6267e9f13aa2f7 is starting a new election at term 177
2018-10-24 10:19:35.606292 I | raft: 4c6267e9f13aa2f7 became candidate at term 178
2018-10-24 10:19:35.606305 I | raft: 4c6267e9f13aa2f7 received MsgVoteResp from 4c6267e9f13aa2f7 at term 178
2018-10-24 10:19:35.606317 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to be72e21dcb4948d0 at term 178
2018-10-24 10:19:35.606328 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to f91b7b5a837d265d at term 178
2018-10-24 10:19:35.606342 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to 14ef5a1bb6b7a26e at term 178
2018-10-24 10:19:37.462312 W | rafthttp: health check for peer f91b7b5a837d265d could not connect: dial tcp 10.233.66.4:2380: i/o timeout
2018-10-24 10:19:37.462387 W | rafthttp: health check for peer 14ef5a1bb6b7a26e could not connect: dial tcp [fe80::b0a2:faff:fe12:8ada]:2380: connect: invalid argument
2018-10-24 10:19:37.506302 I | raft: 4c6267e9f13aa2f7 is starting a new election at term 178
2018-10-24 10:19:37.506366 I | raft: 4c6267e9f13aa2f7 became candidate at term 179
2018-10-24 10:19:37.506386 I | raft: 4c6267e9f13aa2f7 received MsgVoteResp from 4c6267e9f13aa2f7 at term 179
2018-10-24 10:19:37.506407 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to be72e21dcb4948d0 at term 179
2018-10-24 10:19:37.506436 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to f91b7b5a837d265d at term 179
2018-10-24 10:19:37.506449 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to 14ef5a1bb6b7a26e at term 179
2018-10-24 10:19:38.790232 W | etcdserver: read-only range request "key:"foo" " with result "error:context canceled" took too long (4.999078675s) to execute
WARNING: 2018/10/24 10:19:38 grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"
2018-10-24 10:19:38.852524 W | etcdserver: read-only range request "key:"foo" " with result "error:context deadline exceeded" took too long (4.999572884s) to execute
2018-10-24 10:19:38.906267 I | raft: 4c6267e9f13aa2f7 is starting a new election at term 179
2018-10-24 10:19:38.906326 I | raft: 4c6267e9f13aa2f7 became candidate at term 180
2018-10-24 10:19:38.906345 I | raft: 4c6267e9f13aa2f7 received MsgVoteResp from 4c6267e9f13aa2f7 at term 180
2018-10-24 10:19:38.906363 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to be72e21dcb4948d0 at term 180
2018-10-24 10:19:38.906378 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to f91b7b5a837d265d at term 180
2018-10-24 10:19:38.906393 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to 14ef5a1bb6b7a26e at term 180
2018-10-24 10:19:40.006412 I | raft: 4c6267e9f13aa2f7 is starting a new election at term 180
2018-10-24 10:19:40.006491 I | raft: 4c6267e9f13aa2f7 became candidate at term 181
2018-10-24 10:19:40.006514 I | raft: 4c6267e9f13aa2f7 received MsgVoteResp from 4c6267e9f13aa2f7 at term 181
2018-10-24 10:19:40.006552 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to be72e21dcb4948d0 at term 181
2018-10-24 10:19:40.006577 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to f91b7b5a837d265d at term 181
2018-10-24 10:19:40.006593 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to 14ef5a1bb6b7a26e at term 181
2018-10-24 10:19:40.791365 W | etcdserver: timed out waiting for read index response
2018-10-24 10:19:41.906274 I | raft: 4c6267e9f13aa2f7 is starting a new election at term 181
2018-10-24 10:19:41.906317 I | raft: 4c6267e9f13aa2f7 became candidate at term 182
2018-10-24 10:19:41.906333 I | raft: 4c6267e9f13aa2f7 received MsgVoteResp from 4c6267e9f13aa2f7 at term 182
2018-10-24 10:19:41.906347 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to be72e21dcb4948d0 at term 182
2018-10-24 10:19:41.906362 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to f91b7b5a837d265d at term 182
2018-10-24 10:19:41.906378 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to 14ef5a1bb6b7a26e at term 182
2018-10-24 10:19:42.462525 W | rafthttp: health check for peer f91b7b5a837d265d could not connect: dial tcp 10.233.66.4:2380: i/o timeout
2018-10-24 10:19:42.462580 W | rafthttp: health check for peer 14ef5a1bb6b7a26e could not connect: dial tcp 10.233.66.5:2380: getsockopt: connection refused
2018-10-24 10:19:42.906241 I | raft: 4c6267e9f13aa2f7 is starting a new election at term 182
2018-10-24 10:19:42.906284 I | raft: 4c6267e9f13aa2f7 became candidate at term 183
2018-10-24 10:19:42.906300 I | raft: 4c6267e9f13aa2f7 received MsgVoteResp from 4c6267e9f13aa2f7 at term 183
2018-10-24 10:19:42.906323 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to 14ef5a1bb6b7a26e at term 183
2018-10-24 10:19:42.906377 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to be72e21dcb4948d0 at term 183
2018-10-24 10:19:42.906392 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to f91b7b5a837d265d at term 183
2018-10-24 10:19:43.836498 W | etcdserver: read-only range request "key:"foo" " with result "error:context deadline exceeded" took too long (4.999092196s) to execute
2018-10-24 10:19:43.907887 W | etcdserver: read-only range request "key:"foo" " with result "error:context deadline exceeded" took too long (5.000107454s) to execute
2018-10-24 10:19:44.206266 I | raft: 4c6267e9f13aa2f7 is starting a new election at term 183
2018-10-24 10:19:44.206328 I | raft: 4c6267e9f13aa2f7 became candidate at term 184
2018-10-24 10:19:44.206350 I | raft: 4c6267e9f13aa2f7 received MsgVoteResp from 4c6267e9f13aa2f7 at term 184
2018-10-24 10:19:44.206364 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to 14ef5a1bb6b7a26e at term 184
2018-10-24 10:19:44.206375 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to be72e21dcb4948d0 at term 184
2018-10-24 10:19:44.206402 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to f91b7b5a837d265d at term 184
2018-10-24 10:19:45.806241 I | raft: 4c6267e9f13aa2f7 is starting a new election at term 184
2018-10-24 10:19:45.806773 I | raft: 4c6267e9f13aa2f7 became candidate at term 185
2018-10-24 10:19:45.806786 I | raft: 4c6267e9f13aa2f7 received MsgVoteResp from 4c6267e9f13aa2f7 at term 185
2018-10-24 10:19:45.806798 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to be72e21dcb4948d0 at term 185
2018-10-24 10:19:45.806808 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to f91b7b5a837d265d at term 185
2018-10-24 10:19:45.806816 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to 14ef5a1bb6b7a26e at term 185
2018-10-24 10:19:46.906285 I | raft: 4c6267e9f13aa2f7 is starting a new election at term 185
2018-10-24 10:19:46.906331 I | raft: 4c6267e9f13aa2f7 became candidate at term 186
2018-10-24 10:19:46.906346 I | raft: 4c6267e9f13aa2f7 received MsgVoteResp from 4c6267e9f13aa2f7 at term 186
2018-10-24 10:19:46.906360 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to be72e21dcb4948d0 at term 186
2018-10-24 10:19:46.906377 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to f91b7b5a837d265d at term 186
2018-10-24 10:19:46.906389 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to 14ef5a1bb6b7a26e at term 186
2018-10-24 10:19:47.462769 W | rafthttp: health check for peer f91b7b5a837d265d could not connect: dial tcp 10.233.66.4:2380: i/o timeout
2018-10-24 10:19:47.462821 W | rafthttp: health check for peer 14ef5a1bb6b7a26e could not connect: dial tcp [fe80::b0a2:faff:fe12:8ada]:2380: connect: invalid argument
2018-10-24 10:19:47.791584 W | etcdserver: timed out waiting for read index response
2018-10-24 10:19:47.906243 I | raft: 4c6267e9f13aa2f7 is starting a new election at term 186
2018-10-24 10:19:47.906301 I | raft: 4c6267e9f13aa2f7 became candidate at term 187
2018-10-24 10:19:47.906326 I | raft: 4c6267e9f13aa2f7 received MsgVoteResp from 4c6267e9f13aa2f7 at term 187
2018-10-24 10:19:47.906356 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to be72e21dcb4948d0 at term 187
2018-10-24 10:19:47.906383 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to f91b7b5a837d265d at term 187
2018-10-24 10:19:47.906402 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to 14ef5a1bb6b7a26e at term 187
2018-10-24 10:19:48.918309 W | etcdserver: read-only range request "key:"foo" " with result "error:context deadline exceeded" took too long (4.99918868s) to execute
2018-10-24 10:19:49.406250 I | raft: 4c6267e9f13aa2f7 is starting a new election at term 187
2018-10-24 10:19:49.406309 I | raft: 4c6267e9f13aa2f7 became candidate at term 188
2018-10-24 10:19:49.406322 I | raft: 4c6267e9f13aa2f7 received MsgVoteResp from 4c6267e9f13aa2f7 at term 188
2018-10-24 10:19:49.406339 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to be72e21dcb4948d0 at term 188
2018-10-24 10:19:49.406355 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to f91b7b5a837d265d at term 188
2018-10-24 10:19:49.406377 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to 14ef5a1bb6b7a26e at term 188
2018-10-24 10:19:50.606255 I | raft: 4c6267e9f13aa2f7 is starting a new election at term 188
2018-10-24 10:19:50.606295 I | raft: 4c6267e9f13aa2f7 became candidate at term 189
2018-10-24 10:19:50.606318 I | raft: 4c6267e9f13aa2f7 received MsgVoteResp from 4c6267e9f13aa2f7 at term 189
2018-10-24 10:19:50.606330 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to be72e21dcb4948d0 at term 189
2018-10-24 10:19:50.606341 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to f91b7b5a837d265d at term 189
2018-10-24 10:19:50.606353 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to 14ef5a1bb6b7a26e at term 189
2018-10-24 10:19:51.706282 I | raft: 4c6267e9f13aa2f7 is starting a new election at term 189
2018-10-24 10:19:51.706353 I | raft: 4c6267e9f13aa2f7 became candidate at term 190
2018-10-24 10:19:51.706374 I | raft: 4c6267e9f13aa2f7 received MsgVoteResp from 4c6267e9f13aa2f7 at term 190
2018-10-24 10:19:51.706398 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to f91b7b5a837d265d at term 190
2018-10-24 10:19:51.706415 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to 14ef5a1bb6b7a26e at term 190
2018-10-24 10:19:51.706430 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to be72e21dcb4948d0 at term 190
2018-10-24 10:19:52.462978 W | rafthttp: health check for peer 14ef5a1bb6b7a26e could not connect: dial tcp 10.233.66.5:2380: getsockopt: connection refused
2018-10-24 10:19:52.463092 W | rafthttp: health check for peer f91b7b5a837d265d could not connect: dial tcp 10.233.66.4:2380: i/o timeout
2018-10-24 10:19:53.506232 I | raft: 4c6267e9f13aa2f7 is starting a new election at term 190
2018-10-24 10:19:53.506290 I | raft: 4c6267e9f13aa2f7 became candidate at term 191
2018-10-24 10:19:53.506304 I | raft: 4c6267e9f13aa2f7 received MsgVoteResp from 4c6267e9f13aa2f7 at term 191
2018-10-24 10:19:53.506318 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to be72e21dcb4948d0 at term 191
2018-10-24 10:19:53.506328 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to f91b7b5a837d265d at term 191
2018-10-24 10:19:53.506336 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to 14ef5a1bb6b7a26e at term 191
2018-10-24 10:19:53.983823 W | etcdserver: read-only range request "key:"foo" " with result "error:context deadline exceeded" took too long (4.999282334s) to execute
2018-10-24 10:19:54.791773 W | etcdserver: timed out waiting for read index response
2018-10-24 10:19:55.006229 I | raft: 4c6267e9f13aa2f7 is starting a new election at term 191
2018-10-24 10:19:55.006284 I | raft: 4c6267e9f13aa2f7 became candidate at term 192
2018-10-24 10:19:55.006296 I | raft: 4c6267e9f13aa2f7 received MsgVoteResp from 4c6267e9f13aa2f7 at term 192
2018-10-24 10:19:55.006307 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to f91b7b5a837d265d at term 192
2018-10-24 10:19:55.006321 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to 14ef5a1bb6b7a26e at term 192
2018-10-24 10:19:55.006330 I | raft: 4c6267e9f13aa2f7 [logterm: 47, index: 166] sent MsgVote request to be72e21dcb4948d0 at term 192
2018-10-24 10:19:55.179081 W | etcdserver: read-only range request "key:"foo" " with result "error:context canceled" took too long (5.000488915s) to execute
WARNING: 2018/10/24 10:19:55 grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"
2018-10-24 10:19:55.189207 N | pkg/osutil: received terminated signal, shutting down...
2018-10-24 10:19:55.189536 I | etcdserver: skipped leadership transfer for stopping non-leader member
2018-10-24 10:19:55.191717 W | etcdserver: read-only range request "key:"foo" " with result "error:context canceled" took too long (1.147865597s) to execute
WARNING: 2018/10/24 10:19:55 grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"
2018-10-24 10:19:55.191990 I | rafthttp: stopped HTTP pipelining with peer f91b7b5a837d265d
2018-10-24 10:19:55.192014 I | rafthttp: stopped HTTP pipelining with peer be72e21dcb4948d0
2018-10-24 10:19:55.192022 I | rafthttp: stopping peer 14ef5a1bb6b7a26e...
2018-10-24 10:19:55.192033 I | rafthttp: stopped streaming with peer 14ef5a1bb6b7a26e (writer)
2018-10-24 10:19:55.192041 I | rafthttp: stopped streaming with peer 14ef5a1bb6b7a26e (writer)
2018-10-24 10:19:55.192058 I | rafthttp: stopped HTTP pipelining with peer 14ef5a1bb6b7a26e
2018-10-24 10:19:55.192076 I | rafthttp: stopped streaming with peer 14ef5a1bb6b7a26e (stream MsgApp v2 reader)
2018-10-24 10:19:55.192086 I | rafthttp: stopped streaming with peer 14ef5a1bb6b7a26e (stream Message reader)
2018-10-24 10:19:55.192098 I | rafthttp: stopped peer 14ef5a1bb6b7a26e
2018-10-24 10:19:55.192104 I | rafthttp: stopping peer be72e21dcb4948d0...
2018-10-24 10:19:55.192443 I | rafthttp: closed the TCP streaming connection with peer be72e21dcb4948d0 (stream MsgApp v2 writer)
2018-10-24 10:19:55.192460 I | rafthttp: stopped streaming with peer be72e21dcb4948d0 (writer)
2018-10-24 10:19:55.195847 I | rafthttp: closed the TCP streaming connection with peer be72e21dcb4948d0 (stream Message writer)
2018-10-24 10:19:55.195892 I | rafthttp: stopped streaming with peer be72e21dcb4948d0 (writer)
2018-10-24 10:19:55.196079 I | rafthttp: stopped HTTP pipelining with peer be72e21dcb4948d0
2018-10-24 10:19:55.196100 I | rafthttp: stopped streaming with peer be72e21dcb4948d0 (stream MsgApp v2 reader)
2018-10-24 10:19:55.196112 I | rafthttp: stopped streaming with peer be72e21dcb4948d0 (stream Message reader)
2018-10-24 10:19:55.196118 I | rafthttp: stopped peer be72e21dcb4948d0
2018-10-24 10:19:55.196138 I | rafthttp: stopping peer f91b7b5a837d265d...
2018-10-24 10:19:55.196532 I | rafthttp: closed the TCP streaming connection with peer f91b7b5a837d265d (stream MsgApp v2 writer)
2018-10-24 10:19:55.196543 I | rafthttp: stopped streaming with peer f91b7b5a837d265d (writer)
2018-10-24 10:19:55.197087 I | rafthttp: closed the TCP streaming connection with peer f91b7b5a837d265d (stream Message writer)
2018-10-24 10:19:55.197099 I | rafthttp: stopped streaming with peer f91b7b5a837d265d (writer)
2018-10-24 10:19:55.197552 I | rafthttp: stopped HTTP pipelining with peer f91b7b5a837d265d
2018-10-24 10:19:55.197580 I | rafthttp: stopped streaming with peer f91b7b5a837d265d (stream MsgApp v2 reader)
2018-10-24 10:19:55.197596 I | rafthttp: stopped streaming with peer f91b7b5a837d265d (stream Message reader)
2018-10-24 10:19:55.197603 I | rafthttp: stopped peer f91b7b5a837d265d

@atinmu
Copy link

atinmu commented Oct 26, 2018

@rmadaka @ksandha Did we try to test this with etcd 3.2 ?

@rmadaka
Copy link
Author

rmadaka commented Oct 26, 2018

@atinmu Yes atin, I tried with etcd 3.2.24 as well, i am able hit same issue.

@atinmu
Copy link

atinmu commented Oct 26, 2018

@Madhu-1 Can we please talk to some of the etcd folks to (through an issue) to understand what's going wrong here?

@Madhu-1
Copy link
Member

Madhu-1 commented Oct 26, 2018

@atinmu created ETCD issue for this coreos/etcd-operator#2004

@Madhu-1
Copy link
Member

Madhu-1 commented Oct 30, 2018

@rmadaka are we hitting this issue coreos/etcd-operator#1130?

@Madhu-1
Copy link
Member

Madhu-1 commented Oct 31, 2018

some more logs after debugging

2018-10-31 01:32:30.051240 W | etcdserver: failed to send out heartbeat on time (exceeded the 100ms timeout for 7h58m28.433084012s)
2018-10-31 01:32:30.057126 W | etcdserver: server is likely overloaded
2018-10-31 01:32:30.057174 W | etcdserver: failed to send out heartbeat on time (exceeded the 100ms timeout for 7h58m28.445933143s)
2018-10-31 01:32:30.057192 W | etcdserver: server is likely overloaded
2018-10-31 01:32:30.432478 I | rafthttp: peer e145772fa2ab83d0 became inactive
2018-10-31 01:32:30.514549 W | etcdserver: failed to send out heartbeat on time (exceeded the 100ms timeout for 257.316512ms)
2018-10-31 01:32:30.514594 W | etcdserver: server is likely overloaded
2018-10-31 01:32:30.553460 W | etcdserver: failed to send out heartbeat on time (exceeded the 100ms timeout for 296.217375ms)
2018-10-31 01:32:30.553504 W | etcdserver: server is likely overloaded
2018-10-31 01:32:30.798787 W | etcdserver: failed to send out heartbeat on time (exceeded the 100ms timeout for 45.233282ms)
2018-10-31 01:32:30.798831 W | etcdserver: server is likely overloaded
2018-10-31 01:32:30.803925 W | etcdserver: failed to send out heartbeat on time (exceeded the 100ms timeout for 45.329128ms)
2018-10-31 01:32:30.803989 W | etcdserver: server is likely overloaded
2018-10-31 01:32:31.200229 W | etcdserver: failed to send out heartbeat on time (exceeded the 100ms timeout for 47.505277ms)
2018-10-31 01:32:31.208795 W | etcdserver: server is likely overloaded
2018-10-31 01:32:31.208918 W | etcdserver: failed to send out heartbeat on time (exceeded the 100ms timeout for 56.254376ms)
2018-10-31 01:32:31.208939 W | etcdserver: server is likely overloaded

2018-10-30 17:33:50.820714 W | etcdserver: timed out waiting for read index response
2018-10-30 17:33:50.822957 W | etcdserver: read-only range request "key:\"foo\" " with result "range_response_count:0 size:4" took too long (4.23856839s) to execute
2018-10-31 01:32:27.945675 W | rafthttp: lost the TCP streaming connection with peer e145772fa2ab83d0 (stream MsgApp v2 reader)
2018-10-31 01:32:29.979183 E | rafthttp: failed to read e145772fa2ab83d0 on stream MsgApp v2 (read tcp 10.233.66.4:59888->10.233.64.5:2380: i/o timeout)
2018-10-31 01:32:29.991275 W | rafthttp: lost the TCP streaming connection with peer 5582dffc621aa7cc (stream Message reader)
2018-10-31 01:32:29.993498 E | rafthttp: failed to read 5582dffc621aa7cc on stream Message (read tcp 10.233.66.4:53098->10.233.65.4:2380: i/o timeout)

@atinmu
Copy link

atinmu commented Nov 1, 2018

@Madhu-1 did you get a chance to test out this by increasing the overall space for etcd? Did that make any difference?

@JohnStrunk
Copy link
Member

2018-10-31 01:32:31.208939 W | etcdserver: server is likely overloaded

Is this a lack of sufficient CPU resources in this environment (pod or VM)?

@ksandha
Copy link

ksandha commented Nov 2, 2018

2018-10-31 01:32:31.208939 W | etcdserver: server is likely overloaded

Is this a lack of sufficient CPU resources in this environment (pod or VM)?

from the infra side we have a plenty of resources available.

@Madhu-1
Copy link
Member

Madhu-1 commented Nov 4, 2018

After extending the root space of the host, now am able to create more PVC

[vagrant@kube1 ~]$ kubectl exec -it etcd-p6wpbc465r /bin/sh -ngcs
 # df -h
Filesystem                Size      Used Available Use% Mounted on
overlay                  26.8G      5.4G     21.3G  20% /
tmpfs                     1.4G         0      1.4G   0% /dev
tmpfs                     1.4G         0      1.4G   0% /sys/fs/cgroup
/dev/mapper/atomicos-root
                         26.8G      5.4G     21.3G  20% /var/etcd
/dev/mapper/atomicos-root
                         26.8G      5.4G     21.3G  20% /dev/termination-log
/dev/mapper/atomicos-root
                         26.8G      5.4G     21.3G  20% /etc/resolv.conf
/dev/mapper/atomicos-root
                         26.8G      5.4G     21.3G  20% /etc/hostname
/dev/mapper/atomicos-root
                         26.8G      5.4G     21.3G  20% /etc/hosts
shm                      64.0M         0     64.0M   0% /dev/shm
/dev/mapper/atomicos-root
                         26.8G      5.4G     21.3G  20% /run/secrets
tmpfs                     1.4G         0      1.4G   0% /proc/kcore
tmpfs                     1.4G         0      1.4G   0% /proc/timer_list
tmpfs                     1.4G         0      1.4G   0% /proc/timer_stats
tmpfs                     1.4G         0      1.4G   0% /proc/sched_debug
tmpfs                     1.4G         0      1.4G   0% /proc/scsi
tmpfs                     1.4G         0      1.4G   0% /sys/firmware
[vagrant@kube1 ~]$ kubectl get pvc
gcs-pvc                                          Bound     pvc-bf9d3f59e06311e8   1Gi        RWX            glusterfs-csi   26m
gcs-pvc-test1                                    Bound     pvc-2045563be06611e8   1Gi        RWX            glusterfs-csi   9m7s
gcs-pvc-test10                                   Bound     pvc-73255cafe06611e8   1Gi        RWX            glusterfs-csi   6m48s
gcs-pvc-test11                                   Bound     pvc-7c6da80ae06611e8   1Gi        RWX            glusterfs-csi   6m32s
gcs-pvc-test12                                   Bound     pvc-85a28002e06611e8   1Gi        RWX            glusterfs-csi   6m17s
gcs-pvc-test1202019181716151413121110987654321   Bound     pvc-06742fdae06611e8   1Gi        RWX            glusterfs-csi   9m50s
gcs-pvc-test13                                   Bound     pvc-8eca2171e06611e8   1Gi        RWX            glusterfs-csi   6m1s
gcs-pvc-test14                                   Bound     pvc-97f6bd42e06611e8   1Gi        RWX            glusterfs-csi   5m46s
gcs-pvc-test15                                   Bound     pvc-a121e9dfe06611e8   1Gi        RWX            glusterfs-csi   5m31s
gcs-pvc-test16                                   Bound     pvc-aa3ee6a7e06611e8   1Gi        RWX            glusterfs-csi   5m15s
gcs-pvc-test17                                   Bound     pvc-b374cfcee06611e8   1Gi        RWX            glusterfs-csi   5m
gcs-pvc-test18                                   Bound     pvc-bcacabbce06611e8   1Gi        RWX            glusterfs-csi   4m44s
gcs-pvc-test19                                   Bound     pvc-c5fe629be06611e8   1Gi        RWX            glusterfs-csi   4m29s
gcs-pvc-test2                                    Bound     pvc-29722b98e06611e8   1Gi        RWX            glusterfs-csi   8m51s
gcs-pvc-test20                                   Bound     pvc-cf29367fe06611e8   1Gi        RWX            glusterfs-csi   4m13s
gcs-pvc-test21                                   Bound     pvc-d8645005e06611e8   1Gi        RWX            glusterfs-csi   3m58s
gcs-pvc-test3                                    Bound     pvc-328fffc4e06611e8   1Gi        RWX            glusterfs-csi   8m36s
gcs-pvc-test4                                    Bound     pvc-3bc77ae1e06611e8   1Gi        RWX            glusterfs-csi   8m21s
gcs-pvc-test5                                    Bound     pvc-4518521de06611e8   1Gi        RWX            glusterfs-csi   8m5s
gcs-pvc-test6                                    Bound     pvc-4e4ad1e9e06611e8   1Gi        RWX            glusterfs-csi   7m50s
gcs-pvc-test7                                    Bound     pvc-5781fcbce06611e8   1Gi        RWX            glusterfs-csi   7m34s
gcs-pvc-test8                                    Bound     pvc-60c37ffde06611e8   1Gi        RWX            glusterfs-csi   7m19s
gcs-pvc-test9                                    Bound     pvc-69e64838e06611e8   1Gi        RWX            glusterfs-csi   7m3s
gcs-pvc1010987654321                             Bound     pvc-d1833777e06411e8   1Gi        RWX            glusterfs-csi   18m
gcs-pvc11                                        Bound     pvc-f90fc058e06311e8   1Gi        RWX            glusterfs-csi   24m
gcs-pvc111110987654321                           Bound     pvc-e990f125e06411e8   1Gi        RWX            glusterfs-csi   17m
gcs-pvc12121110987654321                         Bound     pvc-01ab964ce06511e8   1Gi        RWX            glusterfs-csi   17m
gcs-pvc1313121110987654321                       Bound     pvc-19b320c6e06511e8   1Gi        RWX            glusterfs-csi   16m
gcs-pvc141413121110987654321                     Bound     pvc-31c96735e06511e8   1Gi        RWX            glusterfs-csi   15m
gcs-pvc15151413121110987654321                   Bound     pvc-49e6af9ce06511e8   1Gi        RWX            glusterfs-csi   15m
gcs-pvc1616151413121110987654321                 Bound     pvc-61e5dc68e06511e8   1Gi        RWX            glusterfs-csi   14m
gcs-pvc171716151413121110987654321               Bound     pvc-7a0e4c5ee06511e8   1Gi        RWX            glusterfs-csi   13m
gcs-pvc18181716151413121110987654321             Bound     pvc-921683eae06511e8   1Gi        RWX            glusterfs-csi   13m
gcs-pvc1919181716151413121110987654321           Bound     pvc-aa32f3e4e06511e8   1Gi        RWX            glusterfs-csi   12m
gcs-pvc202019181716151413121110987654321         Bound     pvc-c23cea6ce06511e8   1Gi        RWX            glusterfs-csi   11m
gcs-pvc221                                       Bound     pvc-11336d03e06411e8   1Gi        RWX            glusterfs-csi   23m
gcs-pvc3321                                      Bound     pvc-2937c477e06411e8   1Gi        RWX            glusterfs-csi   23m
gcs-pvc44321                                     Bound     pvc-414c917ce06411e8   1Gi        RWX            glusterfs-csi   22m
gcs-pvc554321                                    Bound     pvc-594a4f5fe06411e8   1Gi        RWX            glusterfs-csi   21m
gcs-pvc6654321                                   Bound     pvc-71582d09e06411e8   1Gi        RWX            glusterfs-csi   21m
gcs-pvc77654321                                  Bound     pvc-8971abdde06411e8   1Gi        RWX            glusterfs-csi   20m
gcs-pvc887654321                                 Bound     pvc-a17c13b4e06411e8   1Gi        RWX            glusterfs-csi   19m
gcs-pvc9987654321                                Bound     pvc-b9845a3ee06411e8   1Gi        RWX            glusterfs-csi   19m

@rmadaka
Copy link
Author

rmadaka commented Nov 21, 2018

@atinmu With latest build, easily i am able to reproduce this issue. i will give my setup to madhu

@rmadaka
Copy link
Author

rmadaka commented Dec 5, 2018

Adding my observations here,
Created setup with 32GB RAM and 4 VCPUS,
I have tried to create 1000 PVC , 698 pvcs bound, remaining all went to pending state.

After 2 hours of idle time , i have observed the etcd pods went to completed state.

[vagrant@kube1 ~]$ kubectl -n gcs get pods
NAME                                   READY   STATUS             RESTARTS   AGE
csi-attacher-glusterfsplugin-0         2/2     Running            0          23h
csi-nodeplugin-glusterfsplugin-dwkjg   2/2     Running            0          23h
csi-nodeplugin-glusterfsplugin-rb68k   2/2     Running            0          23h
csi-nodeplugin-glusterfsplugin-wbf88   2/2     Running            0          23h
csi-provisioner-glusterfsplugin-0      3/3     Running            0          23h
etcd-9w7dvgtmdv                        0/1     Completed          0          23h
etcd-operator-7cb5bd459b-6q65x         1/1     Running            1          23h
etcd-vxrh55mfmz                        0/1     Completed          0          23h
etcd-vztvwqnqbr                        0/1     Running            0          23h
gluster-kube1-0                        0/1     CrashLoopBackOff   241        23h
gluster-kube2-0                        1/1     Running            1          23h
gluster-kube3-0                        1/1     Running            241        23h

I have observed etcd logs as well, mostly i have seen below are the log error messages repeatedly coming.

2018-12-04 13:19:11.655078 E | rafthttp: failed to read b8f3c3dcdeabb553 on stream MsgApp v2 (read tcp 10.233.64.4:44762->10.233.65.4:2380: i/o timeout)


2018-12-04 13:05:05.803533 E | rafthttp: failed to write f1616b864faa7142 on stream Message (write tcp 10.233.64.4:2380->10.233.66.5:35156: write: broken pipe)


2018-12-04 13:08:08.373721 E | rafthttp: failed to read f1616b864faa7142 on stream MsgApp v2 (read tcp 10.233.64.4:46854->10.233.66.5:2380: i/o timeout)


2018-12-04 13:20:01.589673 E | rafthttp: failed to dial b8f3c3dcdeabb553 on stream Message (read tcp 10.233.64.4:49396->10.233.65.4:2380: i/o timeout)


2018-12-04 13:37:50.079938 E | rafthttp: failed to heartbeat f1616b864faa7142 on stream Message (write tcp 10.233.64.4:2380->10.233.66.5:35532: write: broken pipe)

I have observed kubernetes events as well. below are the events observed continuously

51s         Normal   ExternalProvisioning   PersistentVolumeClaim   waiting for a volume to be created, either by external provisioner "org.gluster.glusterfs" or manually created by system administrator
51s         Normal   ExternalProvisioning   PersistentVolumeClaim   waiting for a volume to be created, either by external provisioner "org.gluster.glusterfs" or manually created by system administrator
51s         Normal   ExternalProvisioning   PersistentVolumeClaim   waiting for a volume to be created, either by external provisioner "org.gluster.glusterfs" or manually created by system administrator
50s         Normal   ExternalProvisioning   PersistentVolumeClaim   waiting for a volume to be created, either by external provisioner "org.gluster.glusterfs" or manually created by system administrator
50s         Normal   ExternalProvisioning   PersistentVolumeClaim   waiting for a volume to be created, either by external provisioner "org.gluster.glusterfs" or manually created by system administrator
50s         Normal   ExternalProvisioning   PersistentVolumeClaim   waiting for a volume to be created, either by external provisioner "org.gluster.glusterfs" or manually created by system administrator
50s         Normal   ExternalProvisioning   PersistentVolumeClaim   waiting for a volume to be created, either by external provisioner "org.gluster.glusterfs" or manually created by system administrator
51s         Normal   ExternalProvisioning   PersistentVolumeClaim   waiting for a volume to be created, either by external provisioner "org.gluster.glusterfs" or manually created by system administrator
51s         Normal   ExternalProvisioning   PersistentVolumeClaim   waiting for a volume to be created, either by external provisioner "org.gluster.glusterfs" or manually created by system administrator
50s         Normal   ExternalProvisioning   PersistentVolumeClaim   waiting for a volume to be created, either by external provisioner "org.gluster.glusterfs" or manually created by system administrator
50s         Normal   ExternalProvisioning   PersistentVolumeClaim   waiting for a volume to be created, either by external provisioner "org.gluster.glusterfs" or manually created by system administrator
50s         Normal   ExternalProvisioning   PersistentVolumeClaim   waiting for a volume to be created, either by external provisioner "org.gluster.glusterfs" or manually created by system administrator
51s         Normal   ExternalProvisioning   PersistentVolumeClaim   waiting for a volume to be created, either by external provisioner "org.gluster.glusterfs" or manually created by system administrator
50s         Normal   ExternalProvisioning   PersistentVolumeClaim   waiting for a volume to be created, either by external provisioner "org.gluster.glusterfs" or manually created by system administrator

I have observed cpu and memory consumption of one of the master node.

vagrant@kube1 ~]$ top

top - 11:32:10 up 1 day, 20 min,  1 user,  load average: 1.31, 0.96, 0.79
Tasks: 10094 total,   1 running, 10093 sleeping,   0 stopped,   0 zombie
%Cpu(s):  7.8 us, 17.4 sy,  0.3 ni, 73.2 id,  0.3 wa,  0.0 hi,  0.9 si,  0.0 st
KiB Mem : 32780948 total, 23865052 free,  3290064 used,  5625832 buff/cache
KiB Swap:        0 total,        0 free,        0 used. 28052136 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                                                                                     
13920 vagrant   20   0   82624  12356   1540 R  66.7  0.0   0:00.51 top                                                                                                                                         
20455 root      20   0  141768  19132   4240 S   9.8  0.1  75:12.48 coredns                                                                                                                                     
13538 root      20   0 1414452 532088  47552 S   7.8  1.6 266:55.74 kubelet                                                                                                                                     
16581 root      20   0 1294872 401988  19268 S   3.9  1.2  75:22.45 hyperkube                                                                                                                                   
    9 root      20   0       0      0      0 S   2.0  0.0   4:29.89 rcu_sched                                                                                                                                   
  531 root      20   0       0      0      0 S   2.0  0.0   0:30.54 xfsaild/dm-0                                                                                                                                
13810 root      20   0  214432  12808   4640 S   2.0  0.0   0:00.11 gluster-exporte                                                                                                                             
16126 root      20   0  499752  27096   4900 S   2.0  0.1   5:31.07 hyperkube                                                                                                                                   
17128 root      20   0  961688 167240  45692 S   2.0  0.5  91:01.36 hyperkube                                                                                                                                   
17332 root      20   0  776432  71724  41788 S   2.0  0.2  20:43.75 hyperkube                                                                                                                                   
21448 root      20   0   10.1g  96200  42072 S   2.0  0.3  28:30.92 etcd                                                                                                                                        
    1 root      20   0  202368  13912   2572 S   0.0  0.0   1:24.30 systemd                                                                                                                                     
    2 root      20   0       0      0      0 S   0.0  0.0   1:31.29 kthreadd                                                                                                                                    
    3 root      20   0       0      0      0 S   0.0  0.0   1:26.56 ksoftirqd/0                                                                                                                                 
    5 root       0 -20       0      0      0 S   0.0  0.0   0:16.74 kworker/0:0H                                                                                                                                
    7 root      rt   0       0      0      0 S   0.0  0.0   0:02.85 migration/0                                                                                                                                 
    8 root      20   0       0      0      0 S   0.0  0.0   0:00.01 rcu_bh                                                                                                                                      
   10 root       0 -20       0      0      0 S   0.0  0.0   0:00.00 lru-add-drain                                                                                                                               
   11 root      rt   0       0      0      0 S   0.0  0.0   0:00.61 watchdog/0                                                                                                                                  
   12 root      rt   0       0      0      0 S   0.0  0.0   0:00.70 watchdog/1                                                                                                                                  
   13 root      rt   0       0      0      0 S   0.0  0.0   0:05.11 migration/1                                                                                                                                 
   14 root      20   0       0      0      0 S   0.0  0.0   0:08.47 ksoftirqd/1                                                                                                                                 
   16 root       0 -20       0      0      0 S   0.0  0.0   0:17.95 kworker/1:0H                                                                                                                                
   17 root      rt   0       0      0      0 S   0.0  0.0   0:03.26 watchdog/2                                                                                                                                  
   18 root      rt   0       0      0      0 S   0.0  0.0   0:02.98 migration/2                                                                                                                                 
   19 root      20   0       0      0      0 S   0.0  0.0   0:07.78 ksoftirqd/2                                                                                                                                 
   21 root       0 -20       0      0      0 S   0.0  0.0   0:03.40 kworker/2:0H                                                                                                                                
   22 root      rt   0       0      0      0 S   0.0  0.0   0:03.07 watchdog/3                                                                                                                                  
   23 root      rt   0       0      0      0 S   0.0  0.0   0:02.79 migration/3                                                                                                                                 
   24 root      20   0       0      0      0 S   0.0  0.0   0:07.39 ksoftirqd/3                                                                                                                                 
   26 root       0 -20       0      0      0 S   0.0  0.0   0:15.09 kworker/3:0H                                                                                                                                
   28 root      20   0       0      0      0 S   0.0  0.0   0:00.38 kdevtmpfs                                                                                                                                   
   29 root       0 -20       0      0      0 S   0.0  0.0   0:00.00 netns                                                                                                                                       
   30 root      20   0       0      0      0 S   0.0  0.0   0:01.31 khungtaskd                                                                                                                                  
   31 root       0 -20       0      0      0 S   0.0  0.0   0:00.00 writeback                                                                                                                                   
   32 root       0 -20       0      0      0 S   0.0  0.0   0:00.00 kintegrityd     

@Madhu-1
Copy link
Member

Madhu-1 commented Dec 5, 2018

@rmadaka memory consumption needs to be checked on ETCD pods.

@ksandha
Copy link

ksandha commented Dec 5, 2018

@Madhu-1

Mem: 1813584K used, 68968K free, 7984K shrd, 0K buff, 784976K cached
CPU:   2% usr   2% sys   0% nic  94% idle   0% io   0% irq   0% sirq
Load average: 0.47 0.55 0.56 2/661 7359
  PID  PPID USER     STAT   VSZ %VSZ CPU %CPU COMMAND
    1     0 root     S   10292m 558%   0   1% /usr/local/bin/etcd --data-dir=/var/etcd/data --name=etcd-r8zv2znhmx --initial-advertise-peer-urls=http://etcd-r8zv2znhmx.etcd.gcs.svc:2380 --listen-peer-urls=http://0.0.0.0:2380 --listen-clie
 7296     0 root     S     1576   0%   1   0% /bin/sh
 7300  7296 root     R     1512   0%   0   0% top

I see virtual memory size (VSZ) clocking to 558%. This is on idle setup. I need to check how VSZ works.

@rmadaka
Copy link
Author

rmadaka commented Dec 6, 2018

Create GCS setup with 16 vcpus and 32GB RAM for each kube node. Then try to create 1000 PVC using script. Each pvc size 1GB.

Observation:

-> I have tried to create 1000 PVC, 615 PVCs are bounded remaining pvcs are in pending state.

-> After 12 hours of idle time observed that GD2 pods rebooted more than 100 times

-> After 12 hour of idle time one of the etcd pod is in not ready state.

[vagrant@kube1 ~]$ kubectl -n gcs get pods
NAME                                   READY   STATUS             RESTARTS   AGE
csi-attacher-glusterfsplugin-0         2/2     Running            0          22h
csi-nodeplugin-glusterfsplugin-b7v2f   2/2     Running            0          22h
csi-nodeplugin-glusterfsplugin-g2vd9   2/2     Running            0          22h
csi-nodeplugin-glusterfsplugin-ppqr2   2/2     Running            0          22h
csi-provisioner-glusterfsplugin-0      3/3     Running            0          22h
etcd-95nxlqf2v7                        1/1     Running            0          22h
etcd-9q9h6mw86w                        1/1     Running            0          22h
etcd-operator-7cb5bd459b-gwdpd         1/1     Running            0          22h
etcd-sf5bntpkh4                        0/1     Running            0          22h
gluster-kube1-0                        1/1     Running            17         22h
gluster-kube2-0                        1/1     Running            199        22h
gluster-kube3-0                        0/1     CrashLoopBackOff   157        22h

-> Observed etcd pods memory and cpu utilization as well. Below observation is after 1000 pvc creation, systems were idle for more than 12 hours, then logged into etcd pod and ran top command

Note : Below are the only two etcd pods memory consumption only, i was not able to login to one more etcd pod, it’s because of that etcd pod not in ready state.

m: 9620728K used, 23158540K free, 30456K shrd, 0K buff, 846448K cached
CPU:   0% usr   0% sys   0% nic 100% idle   0% io   0% irq   0% sirq
Load average: 0.83 0.72 8.94 2/10096 30183
  PID  PPID USER     STAT   VSZ %VSZ CPU %CPU COMMAND
    1     0 root     S   13641m  40%  15   0% /usr/local/bin/etcd --data-dir=/var/etcd/data --name=etcd-95nxlqf2v7 --initial-advertise-peer-urls=http://etcd-95nxlqf2v7.etcd.gcs.svc:2380 --listen-peer-urls=htt
30133     0 root     S     1576   0%  11   0% /bin/sh
 5304     0 root     S     1576   0%   5   0% /bin/sh
30183 30133 root     R     1508   0%  13   0% top
Mem: 10286808K used, 22492460K free, 33300K shrd, 0K buff, 339240K cached
CPU:  14% usr   7% sys   0% nic  74% idle   0% io   0% irq   0% sirq
Load average: 322.85 126.64 86.02 65/27818 2704
  PID  PPID USER     STAT   VSZ %VSZ CPU %CPU COMMAND
    1     0 root     S   13570m  40%   9   0% /usr/local/bin/etcd --data-dir=/var/etcd/data --name=etcd-9q9h6mw86w --initial-advertise-peer-urls=http://etcd-9q9h6mw86w.etcd.gcs.svc:2380 --listen-peer-urls=htt
 2655     0 root     S     1576   0%   5   0% /bin/sh
 2662  2655 root     R     1508   0%   6   0% top

@atinmu
Copy link

atinmu commented Dec 7, 2018

@rmadaka I believe this was due to the constraint on the resource, with 32G RAM and 8 CPU it's not visible any further, correct?

@atinmu atinmu added GCS/0.5 GCS 0.5 release and removed GCS/0.4 GCS 0.4 release GCS/0.5 GCS 0.5 release labels Dec 11, 2018
@JohnStrunk JohnStrunk added the bug Something isn't working label Dec 18, 2018
@rhinduja
Copy link

We did benchmarking around this bug wrt different resources (vcpus and ram)

=> 2 vcpus & 2gb
we were able to scale upto 35 pvc after which the all etcd pods went to completed state.
=> 4 vcpus & 2gb
we were able to scale upto 39 pvc after which the etcd pods went to completed state.
=> 2 vcpus & 4gb
we were able to scale upto 39 pvc after which the etcd pods went to completed state.
=> 4 vcpus & 4gb
we were able to scale upto 64 pvc after which the etcd pods went to completed state.
=> 4 vcpus & 16gb
we were able to scale upto 306 pvc and out of 3 etcd pod cluster we saw the one of the etcd pod went to completed state while 2 of them in running state.
=> 4 vcpus & 32gb
we were able to scale upto 568 pvc and out of 3 etcd pod cluster. Though this time all the etcd were in running state but the pvc's were in PENDING state and were not able to bound.
=> 16 Vcpu & 32gb
we were able to scale upto 623 pvc and out of 3 etcd pod cluster. Though this time all the etcd were in running state but the pvc's were in PENDING state and were not able to bound.

Also, I believe @rmadaka has see one of the etcd in completed state with 8 CPU and 32G RAM in one scenario. Please confirm, Rajesh.

@aravindavk
Copy link
Member

One possible issue is filling up etcd space more than 2GiB and etcd stops accepting more requests with "context deadline exceeded"(Also we need to figure out what is getting filled)

https://coreos.com/etcd/docs/latest/dev-guide/limit.html

Storage size limit

The default storage size limit is 2GB, configurable with
 --quota-backend-bytes flag; supports up to 8GB.

We need a way to configure more size via etcd-operator or env variable.

@aravindavk
Copy link
Member

Fast growing etcd size is discussed here etcd-io/etcd#8009 and solution recommended to use latest version of etcd.

@JohnStrunk
Copy link
Member

Another thing to consider is the snapshot interval and compaction frequency.

It looks like the snapshot interval affects memory usage and storage space will grow indefinitely if compaction isn't enabled, yet for some reason it defaults to off.

I've been playing around w/ these features a bit and I don't have anything concrete at this point, but @rmadaka could probably quickly get a comparison.

For reference, here's an updated gcs-etcd-cluster.yml.j2 with a guess at the above:

---
kind: EtcdCluster
apiVersion: etcd.database.coreos.com/v1beta2
metadata:
  name: etcd
  namespace: {{ gcs_namespace }}
  labels:
    app.kubernetes.io/part-of: gcs
    app.kubernetes.io/component: etcd
    app.kubernetes.io/name: etcd-cluster
spec:
  pod:
    affinity:
      podAntiAffinity:
        preferredDuringSchedulingIgnoredDuringExecution:
        - weight: 100
          podAffinityTerm:
            labelSelector:
              matchExpressions:
              - key: etcd_cluster
                operator: In
                values:
                - etcd
            topologyKey: kubernetes.io/hostname
    etcdEnv:
    # https://github.com/etcd-io/etcd/blob/master/Documentation/op-guide/maintenance.md#auto-compaction
    - name: ETCD_AUTO_COMPACTION_MODE
      value: "periodic"
    - name: ETCD_AUTO_COMPACTION_RETENTION
      value: "5m"
    - name: ETCD_SNAPSHOT_COUNT
      value: "10000"
  size: 3
  version: 3.3.8

# TODO: Setup backup

@atinmu
Copy link

atinmu commented Dec 24, 2018

Fast growing etcd size is discussed here etcd-io/etcd#8009 and solution recommended to use latest version of etcd.

From gcs-etcd-cluster I can see the version is 3.3.8 already?

@aravindavk
Copy link
Member

From gcs-etcd-cluster I can see the version is 3.3.8 already?

Yes. I think we need to try compaction config suggested by @JohnStrunk and increase the etcd storage limit by configuring --quota-backend-bytes to 6GiB or 8GiB(8GiB is maximum) (This also need to be configured using etcdEnv as shown in previous comment)

@aravindavk
Copy link
Member

@rmadaka also add the following to your etcd yml file

    - name: ETCD_QUOTA_BACKEND_BYTES
      value: "8589934592"    # 8 * 1024 * 1024 * 1024 = 8GiB

@ksandha
Copy link

ksandha commented Dec 24, 2018

@aravindavk under etcdEnv ? The updated yaml file looks like the below one. Please correct if anything needs to change.

---
kind: EtcdCluster
apiVersion: etcd.database.coreos.com/v1beta2
metadata:
  name: etcd
  namespace: {{ gcs_namespace }}
  labels:
    app.kubernetes.io/part-of: gcs
    app.kubernetes.io/component: etcd
    app.kubernetes.io/name: etcd-cluster
spec:
  pod:
    affinity:
      podAntiAffinity:
        preferredDuringSchedulingIgnoredDuringExecution:
        - weight: 100
          podAffinityTerm:
            labelSelector:
              matchExpressions:
              - key: etcd_cluster
                operator: In
                values:
                - etcd
            topologyKey: kubernetes.io/hostname
    etcdEnv:
    # https://github.com/etcd-io/etcd/blob/master/Documentation/op-guide/maintenance.md#auto-compaction
    - name: ETCD_AUTO_COMPACTION_MODE
      value: "periodic"
    - name: ETCD_AUTO_COMPACTION_RETENTION
      value: "5m"
    - name: ETCD_SNAPSHOT_COUNT
      value: "10000"
    - name: ETCD_QUOTA_BACKEND_BYTES
      value: "8589934592"    # 8 * 1024 * 1024 * 1024 = 8GiB
  size: 3
  version: 3.3.8

# TODO: Setup backup

@aravindavk
Copy link
Member

@aravindavk under etcdEnv ? The updated yaml file looks like the below one. Please correct if anything needs to change.

LGTM. @Madhu-1 please check

@rmadaka
Copy link
Author

rmadaka commented Dec 24, 2018

@atinmu @JohnStrunk @Madhu-1 @aravindavk

I have tried with above etcd config file and whatever aravinda mentioned about size, same thing i have incorporated in etcd yaml file. Then i have deployed the gcs setup.

I tried for non sequential , My script create pvcs continuously one by one without waiting to get bound previous pvc.

Kube node config: 32 gb ram, 8 vcpus

With Brick -Multiplex:

Script ran for 1000 pvcs, but only 402 pvcs only got bound. after 2 hours of idle time etcd pods went to Error state. after some time one of the kube node went to not ready state.

Need to analyze logs for this.

Without Brick-Multiplex:

Script ran for 1000 PVCs , but only 569 pvcs got bound . but i was not able keep this setup for idle because lack of server space.

I am about to try sequential pvc creation (i mean script will wait till pvc to get bound, then it will go for next pvc creation)

@ksandha
Copy link

ksandha commented Dec 26, 2018

Thanks Rajesh for the update, Below are my observations with brick mux enabled.

  1. Created 1000+ pvc of 50 MB sizes.
  2. Creation was successful upto 200 pvc then the pvc creation stopped for a while and i could see randomly pvc were getting created which were issued later in the stage.
pvc-7ad2c23b-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc497   glusterfs-csi            43h
pvc-7bbc3f8e-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc499   glusterfs-csi            43h
pvc-7c3e38b9-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc500   glusterfs-csi            43h
pvc-7cafab0e-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc501   glusterfs-csi            43h
pvc-7d53b4c8-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc502   glusterfs-csi            43h
pvc-7ddc51eb-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc503   glusterfs-csi            43h
pvc-7e558ac6-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc504   glusterfs-csi            43h
pvc-7eda270b-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc505   glusterfs-csi            43h
pvc-7fcce3d8-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc507   glusterfs-csi            43h
pvc-802e6831-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc508   glusterfs-csi            43h
pvc-811358bb-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc510   glusterfs-csi            43h
pvc-818c214a-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc511   glusterfs-csi            43h
pvc-81f741b2-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc512   glusterfs-csi            43h
pvc-8261c801-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc513   glusterfs-csi            43h
pvc-83e93ce7-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc517   glusterfs-csi            42h
pvc-84d5d91c-075d-11e9-b5d2-525400242e67   500Mi      RWX            Delete           Bound    default/gcs-pvc1     glusterfs-csi            43h
pvc-8d3c8354-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc531   glusterfs-csi            42h
pvc-8dc495e7-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc532   glusterfs-csi            42h
pvc-8e4a4015-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc533   glusterfs-csi            42h
pvc-8ec8c97c-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc534   glusterfs-csi            42h
pvc-9ca03721-075d-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc2     glusterfs-csi            43h
pvc-a08a34d4-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc570   glusterfs-csi            42h
pvc-a1029868-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc571   glusterfs-csi            42h
pvc-a9f25bdf-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc589   glusterfs-csi            42h
pvc-aa965959-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc590   glusterfs-csi            42h
pvc-ab076932-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc591   glusterfs-csi            42h
pvc-abe8a3ba-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc593   glusterfs-csi            42h
pvc-b091be8b-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc603   glusterfs-csi            42h
pvc-b20e4391-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc606   glusterfs-csi            42h
pvc-b27a2386-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc607   glusterfs-csi            42h
pvc-b30b81c0-075e-11e9-b5d2-525400242e67   50Mi       RWX            Delete           Bound    default/gcs-pvc608   glusterfs-csi            42h

  1. While creation is now stopped i have seen the below behaviour in recent builds is that one of the nodes are going in not ready state.
[vagrant@kube1 ~]$ kubectl get nodes
NAME    STATUS     ROLES         AGE   VERSION
kube1   Ready      master,node   45h   v1.12.1
kube2   Ready      master,node   45h   v1.12.1
kube3   NotReady   node          45h   v1.12.1
[vagrant@kube1 ~]$ 
[vagrant@kube1 ~]$ 
[vagrant@kube1 ~]$ 
[vagrant@kube1 ~]$ kubectl get pods -n gcs
NAME                                   READY   STATUS     RESTARTS   AGE
csi-attacher-glusterfsplugin-0         2/2     Running    0          45h
csi-nodeplugin-glusterfsplugin-5lhd5   2/2     Running    0          45h
csi-nodeplugin-glusterfsplugin-dmvwn   2/2     Running    0          45h
csi-nodeplugin-glusterfsplugin-scdmw   2/2     NodeLost   0          45h
csi-provisioner-glusterfsplugin-0      3/3     Unknown    0          45h
etcd-49xffhlb2n                        1/1     Unknown    0          45h
etcd-mp687kpzm4                        1/1     Running    0          112m
etcd-operator-7cb5bd459b-gn59g         1/1     Running    0          41h
etcd-operator-7cb5bd459b-v9z8h         1/1     Unknown    0          45h
etcd-qvr6drsg72                        1/1     Running    0          66m
etcd-w86slhrkbj                        1/1     Running    0          44m
gluster-kube1-0                        1/1     Running    2          19h
gluster-kube2-0                        1/1     Running    4          12h
gluster-kube3-0                        1/1     Unknown    4          43h
[vagrant@kube1 ~]$ 

During the creation of pvc mulitple gd2 pods reboots were seen. especially kube3 was the first among the 3 to restart first. I see the tcd operator pod getting spin on the different node.

@atinmu
Copy link

atinmu commented Dec 26, 2018

@rmadaka @ksandha We need to get all the logs captured and start analyzing one issue at a time.

@ksandha
Copy link

ksandha commented Dec 27, 2018

@atinmu Do we need to carry out the testing with new etcd config suggested by @JohnStrunk & @aravindavk or shall we continue with default config of etcd pods.

atinmu pushed a commit that referenced this issue Dec 30, 2018
@atinmu
Copy link

atinmu commented Dec 30, 2018

It seems the tuning has helped, many thanks @JohnStrunk . In none of our testing setup we couldn't see etcd pods going into completed state :-)

@ksandha
Copy link

ksandha commented Dec 30, 2018

Can we make this default in the latest nightly ?

@ghost ghost removed the bug Something isn't working label Dec 31, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
GCS/0.5 GCS 0.5 release
Projects
None yet
Development

No branches or pull requests

8 participants