Prevote never elect a new leader

[nolouch]

Prevote still has the problem, I have encountered many times in the production. and the log following:
member 7dfa62d3ec9e996b

2018/12/21 22:12:07.064 raft.go:857: [info] 7dfa62d3ec9e996b is starting a new election at term 88
2018/12/21 22:12:07.068 raft.go:684: [info] 7dfa62d3ec9e996b became pre-candidate at term 88
2018/12/21 22:12:07.069 raft.go:755: [info] 7dfa62d3ec9e996b received MsgPreVoteResp from 7dfa62d3ec9e996b at term 88
2018/12/21 22:12:07.069 raft.go:742: [info] 7dfa62d3ec9e996b [logterm: 88, index: 4463981] sent MsgPreVote request to b83a669e9ecde62d at term 88
2018/12/21 22:12:07.069 raft.go:742: [info] 7dfa62d3ec9e996b [logterm: 88, index: 4463981] sent MsgPreVote request to b3ba41b79b56eea at term 88
2018/12/21 22:12:07.179 raft.go:656: [info] 7dfa62d3ec9e996b became follower at term 88
2018/12/21 22:18:33.564 raft.go:857: [info] 7dfa62d3ec9e996b is starting a new election at term 88
2018/12/21 22:18:33.566 raft.go:684: [info] 7dfa62d3ec9e996b became pre-candidate at term 88
2018/12/21 22:18:33.567 raft.go:755: [info] 7dfa62d3ec9e996b received MsgPreVoteResp from 7dfa62d3ec9e996b at term 88
2018/12/21 22:18:33.567 raft.go:742: [info] 7dfa62d3ec9e996b [logterm: 88, index: 4464653] sent MsgPreVote request to b3ba41b79b56eea at term 88
2018/12/21 22:18:33.567 raft.go:742: [info] 7dfa62d3ec9e996b [logterm: 88, index: 4464653] sent MsgPreVote request to b83a669e9ecde62d at term 88
2018/12/21 22:18:33.770 raft.go:782: [info] 7dfa62d3ec9e996b [logterm: 88, index: 4464653, vote: 0] ignored MsgPreVote from b3ba41b79b56eea [logterm: 88, index: 4464653] at term 88: lease is not expired (remaining ticks: 6)
2018/12/21 22:18:35.917 log.go:84: [warning] rafthttp: [lost the TCP streaming connection with peer b83a669e9ecde62d (stream MsgApp v2 reader)]
2018/12/21 22:18:35.918 log.go:82: [error] rafthttp: [failed to read b83a669e9ecde62d on stream MsgApp v2 (read tcp 10.4.5.1:35144->10.4.5.254:2380: i/o timeout)]
2018/12/21 22:18:35.918 log.go:88: [info] rafthttp: [peer b83a669e9ecde62d became inactive]
2018/12/21 22:18:36.016 log.go:84: [warning] rafthttp: [lost the TCP streaming connection with peer b83a669e9ecde62d (stream Message reader)]
2018/12/21 22:18:36.563 raft.go:857: [info] 7dfa62d3ec9e996b is starting a new election at term 88
2018/12/21 22:18:36.563 raft.go:684: [info] 7dfa62d3ec9e996b became pre-candidate at term 88
2018/12/21 22:18:36.563 raft.go:755: [info] 7dfa62d3ec9e996b received MsgPreVoteResp from 7dfa62d3ec9e996b at term 88
2018/12/21 22:18:36.563 raft.go:742: [info] 7dfa62d3ec9e996b [logterm: 88, index: 4464653] sent MsgPreVote request to b83a669e9ecde62d at term 88
2018/12/21 22:18:36.564 raft.go:742: [info] 7dfa62d3ec9e996b [logterm: 88, index: 4464653] sent MsgPreVote request to b3ba41b79b56eea at term 88
2018/12/21 22
:18:36.769 raft.go:782: [info] 7dfa62d3ec9e996b [logterm: 88, index: 4464653, vote: 0] ignored MsgPreVote from b3ba41b79b56eea [logterm: 88, index: 4464653] at term 88: lease is not expired (remaining ticks: 6)
2018/12/21 22:18:39.563 raft.go:857: [info] 7dfa62d3ec9e996b is starting a new election at term 88
2018/12/21 22:18:39.563 raft.go:684: [info] 7dfa62d3ec9e996b became pre-candidate at term 88
2018/12/21 22:18:39.563 raft.go:755: [info] 7dfa62d3ec9e996b received MsgPreVoteResp from 7dfa62d3ec9e996b at term 88
2018/12/21 22:18:39.564 raft.go:742: [info] 7dfa62d3ec9e996b [logterm: 88, index: 4464653] sent MsgPreVote request to b3ba41b79b56eea at term 88
2018/12/21 22:18:39.564 raft.go:742: [info] 7dfa62d3ec9e996b [logterm: 88, index: 4464653] sent MsgPreVote request to b83a669e9ecde62d at term 88
2018/12/21 22:18:39.769 raft.go:782: [info] 7dfa62d3ec9e996b [logterm: 88, index: 4464653, vote: 0] ignored MsgPreVote from b3ba41b79b56eea [logterm: 88, index: 4464653] at term 88: lease is not expired (remaining ticks: 6)
2018/12/21 22:18:42.563 raft.go:857: [info] 7dfa62d3ec9e996b is starting a new election at term 88
2018/12/21 22:18:42.563 raft.go:684: [info] 7dfa62d3ec9e996b became pre-candidate at term 88
2018/12/21 22:18:42.563 raft.go:755: [info] 7dfa62d3ec9e996b received MsgPreVoteResp from 7dfa62d3ec9e996b at term 88
2018/12/21 22:18:42.563 raft.go:742: [info] 7dfa62d3ec9e996b [logterm: 88, index: 4464653] sent MsgPreVote request to b3ba41b79b56eea at term 88
2018/12/21 22:18:42.564 raft.go:742: [info] 7dfa62d3ec9e996b [logterm: 88, index: 4464653] sent MsgPreVote request to b83a669e9ecde62d at term 88
2018/12/21 22:18:42.769 raft.go:782: [info] 7dfa62d3ec9e996b [logterm: 88, index: 4464653, vote: 0] ignored MsgPreVote from b3ba41b79b56eea [logterm: 88, index: 4464653] at term 88: lease is not expired (remaining ticks: 6)
2018/12/21 22:18:45.563 raft.go:857: [info] 7dfa62d3ec9e996b is starting a new election at term 88
2018/12/21 22:18:45.563 raft.go:684: [info] 7dfa62d3ec9e996b became pre-candidate at term 88
2018/12/21 22:18:45.564 raft.go:755: [info] 7dfa62d3ec9e996b received MsgPreVoteResp from 7dfa62d3ec9e996b at term 88
2018/12/21 22:18:45.564 raft.go:742: [info] 7dfa62d3ec9e996b [logterm: 88, index: 4464653] sent MsgPreVote request to b83a669e9ecde62d at term 88
2018/12/21 22:18:45.564 raft.go:742: [info] 7dfa62d3ec9e996b [logterm: 88, index: 4464653] sent MsgPreVote request to b3ba41b79b56eea at term 88
2018/12/21 22:18:45.769 raft.go:782: [info] 7dfa62d3ec9e996b [logterm: 88, index: 4464653, vote: 0] ignored MsgPreVote from b3ba41b79b56eea [logterm: 88, index: 4464653] at term 88: lease is not expired (remaining ticks: 6)

member b3ba41b79b56eea

2018/12/21 22:18:33.768 raft.go:857: [info] b3ba41b79b56eea is starting a new election at term 88
2018/12/21 22:18:33.768 raft.go:684: [info] b3ba41b79b56eea became pre-candidate at term 88
2018/12/21 22:18:33.768 raft.go:755: [info] b3ba41b79b56eea received MsgPreVoteResp from b3ba41b79b56eea at term 88
2018/12/21 22:18:33.768 raft.go:742: [info] b3ba41b79b56eea [logterm: 88, index: 4464653] sent MsgPreVote request to 7dfa62d3ec9e996b at term 88
2018/12/21 22:18:33.768 raft.go:742: [info] b3ba41b79b56eea [logterm: 88, index: 4464653] sent MsgPreVote request to b83a669e9ecde62d at term 88
2018/12/21 22:18:35.916 log.go:84: [warning] rafthttp: [lost the TCP streaming connection with peer b83a669e9ecde62d (stream MsgApp v2 reader)]
2018/12/21 22:18:35.917 log.go:82: [error] rafthttp: [failed to read b83a669e9ecde62d on stream MsgApp v2 (read tcp 10.4.5.253:57280->10.4.5.254:2380: i/o timeout)]
2018/12/21 22:18:35.917 log.go:88: [info] rafthttp: [peer b83a669e9ecde62d became inactive]
2018/12/21 22:18:36.015 log.go:84: [warning] rafthttp: [lost the TCP streaming connection with peer b83a669e9ecde62d (stream Message reader)]
2018/12/21 22:18:36.563 raft.go:782: [info] b3ba41b79b56eea [logterm: 88, index: 4464653, vote: b83a669e9ecde62d] ignored MsgPreVote from 7dfa62d3ec9e996b [logterm: 88, index: 4464653] at term 88: lease is not expired (remaining ticks: 1)
2018/12/21 22:18:36.768 raft.go:857: [info] b3ba41b79b56eea is starting a new election at term 88
2018/12/21 22:18:36.768 raft.go:684: [info] b3ba41b79b56eea became pre-candidate at term 88
2018/12/21 22:18:36.768 raft.go:755: [info] b3ba41b79b56eea received MsgPreVoteResp from b3ba41b79b56eea at term 88
2018/12/21 22:18:36.768 raft.go:742: [info] b3ba41b79b56eea [logterm: 88, index: 4464653] sent MsgPreVote request to b83a669e9ecde62d at term 88
2018/12/21 22:18:36.768 raft.go:742: [info] b3ba41b79b56eea [logterm: 88, index: 4464653] sent MsgPreVote request to 7dfa62d3ec9e996b at term 88
2018/12/21 22:18:39.563 raft.go:782: [info] b3ba41b79b56eea [logterm: 88, index: 4464653, vote: b83a669e9ecde62d] ignored MsgPreVote from 7dfa62d3ec9e996b [logterm: 88, index: 4464653] at term 88: lease is not expired (remaining ticks: 1)
2018/12/21 22:18:39.768 raft.go:857: [info] b3ba41b79b56eea is starting a new election at term 88
2018/12/21 22:18:39.768 raft.go:684: [info] b3ba41b79b56eea became pre-candidate at term 88
2018/12/21 22:18:39.768 raft.go:755: [info] b3ba41b79b56eea received MsgPreVoteResp from b3ba41b79b56eea at term 88
2018/12/21 22:18:39.768 raft.go:742: [info] b3ba41b79b56eea [logterm: 88, index: 4464653] sent MsgPreVote request to 7dfa62d3ec9e996b at term 88
2018/12/21 22:18:39.768 raft.go:742: [info] b3ba41b79b56eea [logterm: 88, index: 4464653] sent MsgPreVote request to b83a669e9ecde62d at term 88
2018/12/21 22:18:42.563 raft.go:782: [info] b3ba41b79b56eea [logterm: 88, index: 4464653, vote: b83a669e9ecde62d] ignored MsgPreVote from 7dfa62d3ec9e996b [logterm: 88, index: 4464653] at term 88: lease is not expired (remaining ticks: 1)
2018/12/21 22:18:42.768 raft.go:857: [info] b3ba41b79b56eea is starting a new election at term 88
2018/12/21 22:18:42.768 raft.go:684: [info] b3ba41b79b56eea became pre-candidate at term 88
2018/12/21 22:18:42.768 raft.go:755: [info] b3ba41b79b56eea received MsgPreVoteResp from b3ba41b79b56eea at term 88
2018/12/21 22:18:42.768 raft.go:742: [info] b3ba41b79b56eea [logterm: 88, index: 4464653] sent MsgPreVote request to 7dfa62d3ec9e996b at term 88
2018/12/21 22:18:42.768 raft.go:742: [info] b3ba41b79b56eea [logterm: 88, index: 4464653] sent MsgPreVote request to b83a669e9ecde62d at term 88
2018/12/21 22:18:43.687 log.go:84: [warning] etcdserver: [read-only range request "key:\"/tidb/store/gcworker/saved_safe_point\" " took too long (4.999919755s) to execute]
2018/12/21 22:18:45.563 raft.go:782: [info] b3ba41b79b56eea [logterm: 88, index: 4464653, vote: b83a669e9ecde62d] ignored MsgPreVote from 7dfa62d3ec9e996b [logterm: 88, index: 4464653] at term 88: lease is not expib83a669e9ecde62dred (remaining ticks: 1)
2018/12/21 22:18:45.768 raft.go:857: [info] b3ba41b79b56eea is starting a new election at term 88
2018/12/21 22:18:45.768 raft.go:684: [info] b3ba41b79b56eea became pre-candidate at term 88
2018/12/21 22:18:45.768 raft.go:755: [info] b3ba41b79b56eea received MsgPreVoteResp from b3ba41b79b56eea at term 88
2018/12/21 22:18:45.768 raft.go:742: [info] b3ba41b79b56eea [logterm: 88, index: 4464653] sent MsgPreVote request to 7dfa62d3ec9e996b at term 88
2018/12/21 22:18:45.768 raft.go:742: [info] b3ba41b79b56eea [logterm: 88, index: 4464653] sent MsgPreVote request to b83a669e9ecde62d at term 88
2018/12/21 22:18:48.563 raft.go:782: [info] b3ba41b79b56eea [logterm: 88, index: 4464653, vote: b83a669e9ecde62d] ignored MsgPreVote from 7dfa62d3ec9e996b [logterm: 88, index: 4464653] at term 88: lease is not expired (remaining ticks: 1)
2018/12/21 22:18:48.768 raft.go:857: [info] b3ba41b79b56eea is starting a new election at term 88
2018/12/21 22:18:48.768 raft.go:684: [info] b3ba41b79b56eea became pre-candidate at term 88
2018/12/21 22:18:48.768 raft.go:755: [info] b3ba41b79b56eea received MsgPreVoteResp from b3ba41b79b56eea at term 88
2018/12/21 22:18:48.768 raft.go:742: [info] b3ba41b79b56eea [logterm: 88, index: 4464653] sent MsgPreVote request to 7dfa62d3ec9e996b at term 88
2018/12/21 22:18:48.768 raft.go:742: [info] b3ba41b79b56eea [logterm: 88, index: 4464653] sent MsgPreVote request to b83a669e9ecde62d at term 88
2018/12/21 22:18:49.683 log.go:84: [warning] etcdserver: [timed out waiting for read index response]
2018/12/21 22:18:51.563 raft.go:782: [info] b3ba41b79b56eea [logterm: 88, index: 4464653, vote: b83a669e9ecde62d] ignored MsgPreVote from 7dfa62d3ec9e996b [logterm: 88, index: 4464653] at term 88: lease is not expired (remaining ticks: 1)

memeber b83a669e9ecde62d down.

as the log show, there are some problem:

1. the randomizedElectionTimeout never changed, so it always keep the state in lease.
2. inLease will be true in high possibility even we reset the randomizedElectionTimeout when becamePreCadidate, the election time may take a long time.

So, can we continue to advance this PR ?
PTAL @xiang90 @bdarnell @gyuho

[xiang90]

#8334 is merged.

[nolouch]

thanks!