Improper restart success condition cause cluster upgrade failure and service outage

Bug Report

Please answer these questions before submitting your issue. Thanks!

1. What did you do?

tiup cluster upgrade <cluster-name> v4.0.6

Cluster upgrades should respect service health before proceeding.

2. What did you expect to see?

PD works fine.

3. What did you see instead?

PD service outage (no leader)

2020/09/15 23:31:48.965 +08:00] [WARN] [grpclog.go:60] ["grpc: addrConn.createTransport failed to connect to {http://172.16.5.69:12379 0  <nil>}. Err :connection error: desc = \"transport: Error while dialing dial tcp 172.16.5.69:12379: connect: connection refused\". Rec
[2020/09/15 23:31:48.965 +08:00] [WARN] [stream.go:436] ["lost TCP streaming connection with remote peer"] [stream-reader-type="stream MsgApp v2"] [local-member-id=432cb549bbc6ba19] [remote-peer-id=4559964b92377b49] [error=EOF]
[2020/09/15 23:31:48.966 +08:00] [WARN] [stream.go:436] ["lost TCP streaming connection with remote peer"] [stream-reader-type="stream Message"] [local-member-id=432cb549bbc6ba19] [remote-peer-id=4559964b92377b49] [error=EOF]
[2020/09/15 23:31:48.970 +08:00] [WARN] [peer_status.go:68] ["peer became inactive (message send to peer failed)"] [peer-id=4559964b92377b49] [error="failed to dial 4559964b92377b49 on stream Message (peer 4559964b92377b49 failed to find local node 432cb549bbc6ba19)"]
[2020/09/15 23:31:49.065 +08:00] [WARN] [grpclog.go:60] ["grpc: addrConn.createTransport failed to connect to {http://172.16.5.69:12379 0  <nil>}. Err :connection error: desc = \"transport: Error while dialing dial tcp 172.16.5.69:12379: connect: connection refused\". Rec
[2020/09/15 23:31:49.253 +08:00] [WARN] [grpclog.go:60] ["grpc: addrConn.createTransport failed to connect to {http://172.16.5.69:12379 0  <nil>}. Err :connection error: desc = \"transport: Error while dialing dial tcp 172.16.5.69:12379: connect: connection refused\". Rec
[2020/09/15 23:31:49.335 +08:00] [WARN] [stream.go:193] ["lost TCP streaming connection with remote peer"] [stream-writer-type="stream Message"] [local-member-id=432cb549bbc6ba19] [remote-peer-id=4559964b92377b49]
[2020/09/15 23:31:50.489 +08:00] [WARN] [stream.go:224] ["lost TCP streaming connection with remote peer"] [stream-writer-type="stream MsgApp v2"] [local-member-id=432cb549bbc6ba19] [remote-peer-id=4559964b92377b49]
[2020/09/15 23:31:54.535 +08:00] [WARN] [grpclog.go:60] ["grpc: addrConn.createTransport failed to connect to {http://172.16.5.69:12379 0  <nil>}: didn't receive server preface in time. Reconnecting..."]
[2020/09/15 23:31:55.947 +08:00] [WARN] [grpclog.go:60] ["grpc: addrConn.createTransport failed to connect to {http://172.16.5.71:12379 0  <nil>}. Err :connection error: desc = \"transport: Error while dialing dial tcp 172.16.5.71:12379: connect: connection refused\". Rec
[2020/09/15 23:31:55.948 +08:00] [WARN] [stream.go:436] ["lost TCP streaming connection with remote peer"] [stream-reader-type="stream MsgApp v2"] [local-member-id=432cb549bbc6ba19] [remote-peer-id=c239b485432fe1ae] [error=EOF]
[2020/09/15 23:31:55.949 +08:00] [WARN] [stream.go:436] ["lost TCP streaming connection with remote peer"] [stream-reader-type="stream Message"] [local-member-id=432cb549bbc6ba19] [remote-peer-id=c239b485432fe1ae] [error=EOF]
[2020/09/15 23:31:55.951 +08:00] [WARN] [peer_status.go:68] ["peer became inactive (message send to peer failed)"] [peer-id=c239b485432fe1ae] [error="failed to dial c239b485432fe1ae on stream MsgApp v2 (peer c239b485432fe1ae failed to find local node 432cb549bbc6ba19)"]
[2020/09/15 23:31:56.048 +08:00] [WARN] [grpclog.go:60] ["grpc: addrConn.createTransport failed to connect to {http://172.16.5.71:12379 0  <nil>}. Err :connection error: desc = \"transport: Error while dialing dial tcp 172.16.5.71:12379: connect: connection refused\". Rec
[2020/09/15 23:31:56.234 +08:00] [WARN] [grpclog.go:60] ["grpc: addrConn.createTransport failed to connect to {http://172.16.5.71:12379 0  <nil>}. Err :connection error: desc = \"transport: Error while dialing dial tcp 172.16.5.71:12379: connect: connection refused\". Rec
[2020/09/15 23:31:56.468 +08:00] [WARN] [grpclog.go:60] ["grpc: addrConn.createTransport failed to connect to {http://172.16.5.71:12379 0  <nil>}. Err :connection error: desc = \"transport: Error while dialing dial tcp 172.16.5.71:12379: connect: connection refused\". Rec
[2020/09/15 23:31:57.254 +08:00] [WARN] [stream.go:224] ["lost TCP streaming connection with remote peer"] [stream-writer-type="stream Message"] [local-member-id=432cb549bbc6ba19] [remote-peer-id=c239b485432fe1ae]
[2020/09/15 23:31:58.269 +08:00] [ERROR] [server.go:260] ["region syncer send data meet error"] [error="rpc error: code = Unavailable desc = transport is closing"]
[2020/09/15 23:31:58.269 +08:00] [INFO] [server.go:269] ["region syncer delete the stream"] [stream=pd-2]
[2020/09/15 23:31:59.337 +08:00] [WARN] [stream.go:193] ["lost TCP streaming connection with remote peer"] [stream-writer-type="stream MsgApp v2"] [local-member-id=432cb549bbc6ba19] [remote-peer-id=c239b485432fe1ae]
[2020/09/15 23:31:59.872 +08:00] [WARN] [grpclog.go:60] ["grpc: addrConn.createTransport failed to connect to {http://172.16.5.69:12379 0  <nil>}: didn't receive server preface in time. Reconnecting..."]
[2020/09/15 23:32:00.253 +08:00] [WARN] [raft.go:1011] ["432cb549bbc6ba19 stepped down to follower since quorum is not active"]
[2020/09/15 23:32:00.253 +08:00] [INFO] [raft.go:700] ["432cb549bbc6ba19 became follower at term 27"]
[2020/09/15 23:32:00.253 +08:00] [INFO] [node.go:331] ["raft.node: 432cb549bbc6ba19 lost leader 432cb549bbc6ba19 at term 27"]

4. What version of TiUP are you using (tiup --version)?

v1.1.2 tiup

Start by reproducing the tiup cluster upgrade v4.0.6 scenario and tracing how restart success is determined. Review the referenced raft.go, node.go, server.go, peer_status.go, and stream.go log locations for the reported no-leader condition. Done means an upgrade does not proceed while the cluster is unhealthy and the failure is covered by a regression test.