ECSサービスへgRPCリクエスト中にECSサービスを更新するとダウンタイムが発生する
Wait-for-Readyを使うことでダウンタイムが発生しにくくなることを検証する
検証する環境と方法
aws構成
クライアントはAWS Cloud MapのDNSを使用してサーバー側ECSタスクを名前解決する
以下各サービスの設定値
- Cloud Map 名前空間
- インスタンスの検出: "API呼び出しとVPCのDNSクエリ"
- TTL: 15秒
- ECSサービス
- 最小実行タスク: 100%
- 最大実行タスク: 200%
- サービス検出
- "Amazon ECS タスク状態の伝達を有効にする": 有効
- DNSレコード
- DNSレコードタイプ: A
- TTL: 15秒
- ECSタスク定義 / サーバー
- 特にコンテナヘルスチェック設定はしていない
- ECSタスク定義 / クライアント
- 特にコンテナヘルスチェック設定はしていない
- 環境変数
- GRPC_GO_LOG_VERBOSITY_LEVEL: 99
- GRPC_GO_LOG_SEVERITY_LEVEL: info
アプリケーション
-
使用する言語、ライブラリ
- Go 1.22
- google.golang.org/grpc v1.63.2
-
サーバーコード
- リクエストされた文字列をそのまま返す
- graceful shutdownを入れている
Gopackage main import ( "context" "log" "net" "os" "os/signal" "syscall" "time" "google.golang.org/grpc" pb "google.golang.org/grpc/examples/features/proto/echo" ) type ecServer struct { pb.UnimplementedEchoServer } func (s *ecServer) UnaryEcho(_ context.Context, req *pb.EchoRequest) (*pb.EchoResponse, error) { time.Sleep(1 * time.Second) return &pb.EchoResponse{Message: req.Message}, nil } func main() { lis, err := net.Listen("tcp", ":50051") if err != nil { log.Fatalf("failed to listen: %v", err) } s := grpc.NewServer() pb.RegisterEchoServer(s, &ecServer{}) ctx, stop := signal.NotifyContext(context.Background(), os.Interrupt, os.Kill, syscall.SIGTERM) defer stop() log.Println("serving on :50051") go func() { if err := s.Serve(lis); err != nil { stop() log.Fatalf("failed to serve: %v", err) } }() <-ctx.Done() log.Println("shutting down") s.GracefulStop() }
-
クライアントコード
- サーバーに"hello"をリクエストしレスポンスを出力する
- これを一定数繰り返す
Gopackage main import ( "context" "log" "os" "time" "google.golang.org/grpc" "google.golang.org/grpc/credentials/insecure" ecpb "google.golang.org/grpc/examples/features/proto/echo" ) func main() { conn, err := grpc.NewClient( "server.grpc.local:50051", // Cloud MapのDNS grpc.WithTransportCredentials(insecure.NewCredentials()), grpc.WithDefaultCallOptions( grpc.WaitForReady(true), // Wait-for-Ready設定 ), ) if err != nil { log.Fatalf("did not connect: %v", err) } defer conn.Close() hwc := ecpb.NewEchoClient(conn) for i := 0; i < 300; i++ { ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) defer cancel() r, err := hwc.UnaryEcho(ctx, &ecpb.EchoRequest{Message: "hello"}) if err != nil { log.Printf("could not invoke: %v\n", err) time.Sleep(1 * time.Second) continue } log.Println(r.Message) } }
検証方法
クライアントをECSタスクで起動し、gRPCリクエスト中にサーバー側ECSサービスを強制更新する
クライアント側ECSタスクのログを確認する
Wait-for-Readyなしのログ
- 新しい接続(10.0.27.158)を見つけるまで"could not invoke: "エラーが出続けている
...
2024/04/20 13:39:35 hello
2024/04/20 13:39:36 hello
2024/04/20 13:39:37 hello
"2024/04/20 13:39:37 INFO: [transport] [client-transport 0x40000eb208] Closing: connection error: desc = ""error reading from server: EOF"""
2024/04/20 13:39:37 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to IDLE
"2024/04/20 13:39:37 INFO: [core] [pick-first-lb 0x400013b0e0] Received SubConn state update: 0x400013b170, {ConnectivityState:IDLE ConnectionError:<nil>}"
2024/04/20 13:39:37 INFO: [transport] [client-transport 0x40000eb208] loopyWriter exiting with error: transport closed by client
2024/04/20 13:39:37 INFO: [core] [Channel #1]Channel Connectivity change to IDLE
2024/04/20 13:39:37 could not invoke: rpc error: code = Unavailable desc = error reading from server: EOF
2024/04/20 13:39:38 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to CONNECTING
"2024/04/20 13:39:38 INFO: [core] [Channel #1 SubChannel #2]Subchannel picks a new address ""10.0.19.136:50051"" to connect"
"2024/04/20 13:39:38 INFO: [core] [pick-first-lb 0x400013b0e0] Received SubConn state update: 0x400013b170, {ConnectivityState:CONNECTING ConnectionError:<nil>}"
2024/04/20 13:39:38 INFO: [core] [Channel #1]Channel Connectivity change to CONNECTING
"2024/04/20 13:39:38 INFO: [core] Creating new client transport to ""{Addr: \""10.0.19.136:50051\"", ServerName: \""server.grpc.local:50051\"", }"": connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:38 WARNING: [core] [Channel #1 SubChannel #2]grpc: addrConn.createTransport failed to connect to {Addr: ""10.0.19.136:50051"", ServerName: ""server.grpc.local:50051"", }. Err: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:38 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to TRANSIENT_FAILURE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:38 INFO: [core] [pick-first-lb 0x400013b0e0] Received SubConn state update: 0x400013b170, {ConnectivityState:TRANSIENT_FAILURE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused""}"
2024/04/20 13:39:38 INFO: [core] [Channel #1]Channel Connectivity change to TRANSIENT_FAILURE
"2024/04/20 13:39:38 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:39 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to IDLE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:39 INFO: [core] [pick-first-lb 0x400013b0e0] Received SubConn state update: 0x400013b170, {ConnectivityState:IDLE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused""}"
"2024/04/20 13:39:39 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
2024/04/20 13:39:39 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to CONNECTING
"2024/04/20 13:39:39 INFO: [core] [Channel #1 SubChannel #2]Subchannel picks a new address ""10.0.19.136:50051"" to connect"
"2024/04/20 13:39:39 INFO: [core] [pick-first-lb 0x400013b0e0] Received SubConn state update: 0x400013b170, {ConnectivityState:CONNECTING ConnectionError:<nil>}"
"2024/04/20 13:39:39 INFO: [core] Creating new client transport to ""{Addr: \""10.0.19.136:50051\"", ServerName: \""server.grpc.local:50051\"", }"": connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:39 WARNING: [core] [Channel #1 SubChannel #2]grpc: addrConn.createTransport failed to connect to {Addr: ""10.0.19.136:50051"", ServerName: ""server.grpc.local:50051"", }. Err: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:39 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to TRANSIENT_FAILURE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:39 INFO: [core] [pick-first-lb 0x400013b0e0] Received SubConn state update: 0x400013b170, {ConnectivityState:TRANSIENT_FAILURE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused""}"
"2024/04/20 13:39:40 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:41 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to IDLE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:41 INFO: [core] [pick-first-lb 0x400013b0e0] Received SubConn state update: 0x400013b170, {ConnectivityState:IDLE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused""}"
2024/04/20 13:39:41 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to CONNECTING
"2024/04/20 13:39:41 INFO: [core] [Channel #1 SubChannel #2]Subchannel picks a new address ""10.0.19.136:50051"" to connect"
"2024/04/20 13:39:41 INFO: [core] [pick-first-lb 0x400013b0e0] Received SubConn state update: 0x400013b170, {ConnectivityState:CONNECTING ConnectionError:<nil>}"
"2024/04/20 13:39:41 INFO: [core] Creating new client transport to ""{Addr: \""10.0.19.136:50051\"", ServerName: \""server.grpc.local:50051\"", }"": connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:41 WARNING: [core] [Channel #1 SubChannel #2]grpc: addrConn.createTransport failed to connect to {Addr: ""10.0.19.136:50051"", ServerName: ""server.grpc.local:50051"", }. Err: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:41 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to TRANSIENT_FAILURE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:41 INFO: [core] [pick-first-lb 0x400013b0e0] Received SubConn state update: 0x400013b170, {ConnectivityState:TRANSIENT_FAILURE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused""}"
"2024/04/20 13:39:41 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:42 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:43 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:44 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to IDLE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:44 INFO: [core] [pick-first-lb 0x400013b0e0] Received SubConn state update: 0x400013b170, {ConnectivityState:IDLE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused""}"
2024/04/20 13:39:44 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to CONNECTING
"2024/04/20 13:39:44 INFO: [core] [Channel #1 SubChannel #2]Subchannel picks a new address ""10.0.19.136:50051"" to connect"
"2024/04/20 13:39:44 INFO: [core] [pick-first-lb 0x400013b0e0] Received SubConn state update: 0x400013b170, {ConnectivityState:CONNECTING ConnectionError:<nil>}"
"2024/04/20 13:39:44 INFO: [core] Creating new client transport to ""{Addr: \""10.0.19.136:50051\"", ServerName: \""server.grpc.local:50051\"", }"": connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:44 WARNING: [core] [Channel #1 SubChannel #2]grpc: addrConn.createTransport failed to connect to {Addr: ""10.0.19.136:50051"", ServerName: ""server.grpc.local:50051"", }. Err: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:44 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to TRANSIENT_FAILURE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:44 INFO: [core] [pick-first-lb 0x400013b0e0] Received SubConn state update: 0x400013b170, {ConnectivityState:TRANSIENT_FAILURE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused""}"
"2024/04/20 13:39:44 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:45 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:46 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:47 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to IDLE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:47 INFO: [core] [pick-first-lb 0x400013b0e0] Received SubConn state update: 0x400013b170, {ConnectivityState:IDLE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused""}"
2024/04/20 13:39:47 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to CONNECTING
"2024/04/20 13:39:47 INFO: [core] [Channel #1 SubChannel #2]Subchannel picks a new address ""10.0.19.136:50051"" to connect"
"2024/04/20 13:39:47 INFO: [core] [pick-first-lb 0x400013b0e0] Received SubConn state update: 0x400013b170, {ConnectivityState:CONNECTING ConnectionError:<nil>}"
"2024/04/20 13:39:47 INFO: [core] Creating new client transport to ""{Addr: \""10.0.19.136:50051\"", ServerName: \""server.grpc.local:50051\"", }"": connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:47 WARNING: [core] [Channel #1 SubChannel #2]grpc: addrConn.createTransport failed to connect to {Addr: ""10.0.19.136:50051"", ServerName: ""server.grpc.local:50051"", }. Err: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:47 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to TRANSIENT_FAILURE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:47 INFO: [core] [pick-first-lb 0x400013b0e0] Received SubConn state update: 0x400013b170, {ConnectivityState:TRANSIENT_FAILURE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused""}"
"2024/04/20 13:39:47 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:48 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:49 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:50 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:51 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:52 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:53 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to IDLE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:53 INFO: [core] [pick-first-lb 0x400013b0e0] Received SubConn state update: 0x400013b170, {ConnectivityState:IDLE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused""}"
2024/04/20 13:39:53 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to CONNECTING
"2024/04/20 13:39:53 INFO: [core] [Channel #1 SubChannel #2]Subchannel picks a new address ""10.0.19.136:50051"" to connect"
"2024/04/20 13:39:53 INFO: [core] [pick-first-lb 0x400013b0e0] Received SubConn state update: 0x400013b170, {ConnectivityState:CONNECTING ConnectionError:<nil>}"
"2024/04/20 13:39:53 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:54 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:55 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:56 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:57 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:58 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:39:59 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:40:00 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:40:01 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:40:02 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:40:03 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:40:04 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:40:05 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
"2024/04/20 13:40:06 could not invoke: rpc error: code = Unavailable desc = connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: connect: connection refused"""
2024/04/20 13:40:07 INFO: [core] [Channel #1]Resolver state updated: {
" ""Addresses"": ["
{
" ""Addr"": ""10.0.27.158:50051"","
" ""ServerName"": """","
" ""Attributes"": null,"
" ""BalancerAttributes"": null,"
" ""Metadata"": null"
}
" ],"
" ""Endpoints"": ["
{
" ""Addresses"": ["
{
" ""Addr"": ""10.0.27.158:50051"","
" ""ServerName"": """","
" ""Attributes"": null,"
" ""BalancerAttributes"": null,"
" ""Metadata"": null"
}
" ],"
" ""Attributes"": null"
}
" ],"
" ""ServiceConfig"": null,"
" ""Attributes"": null"
} ()
2024/04/20 13:40:07 INFO: [core] [pick-first-lb 0x400013b0e0] Received new config {
" ""shuffleAddressList"": false"
"}, resolver state {"
" ""Addresses"": ["
{
" ""Addr"": ""10.0.27.158:50051"","
" ""ServerName"": """","
" ""Attributes"": null,"
" ""BalancerAttributes"": null,"
" ""Metadata"": null"
}
" ],"
" ""Endpoints"": ["
{
" ""Addresses"": ["
{
" ""Addr"": ""10.0.27.158:50051"","
" ""ServerName"": """","
" ""Attributes"": null,"
" ""BalancerAttributes"": null,"
" ""Metadata"": null"
}
" ],"
" ""Attributes"": null"
}
" ],"
" ""ServiceConfig"": null,"
" ""Attributes"": null"
}
2024/04/20 13:40:07 INFO: [core] [Channel #1 SubChannel #2]addrConn: updateAddrs curAddr: {
" ""Addr"": ""10.0.19.136:50051"","
" ""ServerName"": ""server.grpc.local:50051"","
" ""Attributes"": null,"
" ""BalancerAttributes"": null,"
" ""Metadata"": null"
"}, addrs: ["
{
" ""Addr"": ""10.0.27.158:50051"","
" ""ServerName"": """","
" ""Attributes"": null,"
" ""BalancerAttributes"": null,"
" ""Metadata"": null"
}
]
"2024/04/20 13:40:07 INFO: [core] Creating new client transport to ""{Addr: \""10.0.19.136:50051\"", ServerName: \""server.grpc.local:50051\"", }"": connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: operation was canceled"""
"2024/04/20 13:40:07 WARNING: [core] [Channel #1 SubChannel #2]grpc: addrConn.createTransport failed to connect to {Addr: ""10.0.19.136:50051"", ServerName: ""server.grpc.local:50051"", }. Err: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.19.136:50051: operation was canceled"""
"2024/04/20 13:40:07 INFO: [core] [Channel #1 SubChannel #2]Subchannel picks a new address ""10.0.27.158:50051"" to connect"
2024/04/20 13:40:07 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to READY
"2024/04/20 13:40:07 INFO: [core] [pick-first-lb 0x400013b0e0] Received SubConn state update: 0x400013b170, {ConnectivityState:READY ConnectionError:<nil>}"
2024/04/20 13:40:07 INFO: [core] [Channel #1]Channel Connectivity change to READY
2024/04/20 13:40:08 hello
2024/04/20 13:40:09 hello
2024/04/20 13:40:11 hello
...
Wait-for-Readyありのログ
- 接続がなくなる最初に1度"could not invoke: rpc error: code = Unavailable desc = error reading from server: EOF"エラーが出ている
- それ以降新しい接続(10.0.30.165)を見つけるまで"could not invoke: "エラーは出ない
...
2024/04/20 13:43:26 hello
2024/04/20 13:43:27 hello
2024/04/20 13:43:28 hello
"2024/04/20 13:43:29 INFO: [transport] [client-transport 0x40000eb208] Closing: connection error: desc = ""error reading from server: EOF"""
2024/04/20 13:43:29 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to IDLE
"2024/04/20 13:43:29 INFO: [core] [pick-first-lb 0x40001baed0] Received SubConn state update: 0x40001baf60, {ConnectivityState:IDLE ConnectionError:<nil>}"
2024/04/20 13:43:29 INFO: [core] [Channel #1]Channel Connectivity change to IDLE
2024/04/20 13:43:29 INFO: [transport] [client-transport 0x40000eb208] loopyWriter exiting with error: transport closed by client
2024/04/20 13:43:29 could not invoke: rpc error: code = Unavailable desc = error reading from server: EOF
2024/04/20 13:43:30 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to CONNECTING
"2024/04/20 13:43:30 INFO: [core] [Channel #1 SubChannel #2]Subchannel picks a new address ""10.0.27.158:50051"" to connect"
"2024/04/20 13:43:30 INFO: [core] [pick-first-lb 0x40001baed0] Received SubConn state update: 0x40001baf60, {ConnectivityState:CONNECTING ConnectionError:<nil>}"
2024/04/20 13:43:30 INFO: [core] [Channel #1]Channel Connectivity change to CONNECTING
"2024/04/20 13:43:30 INFO: [core] Creating new client transport to ""{Addr: \""10.0.27.158:50051\"", ServerName: \""server.grpc.local:50051\"", }"": connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:30 WARNING: [core] [Channel #1 SubChannel #2]grpc: addrConn.createTransport failed to connect to {Addr: ""10.0.27.158:50051"", ServerName: ""server.grpc.local:50051"", }. Err: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:30 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to TRANSIENT_FAILURE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:30 INFO: [core] [pick-first-lb 0x40001baed0] Received SubConn state update: 0x40001baf60, {ConnectivityState:TRANSIENT_FAILURE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused""}"
2024/04/20 13:43:30 INFO: [core] [Channel #1]Channel Connectivity change to TRANSIENT_FAILURE
"2024/04/20 13:43:31 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to IDLE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:31 INFO: [core] [pick-first-lb 0x40001baed0] Received SubConn state update: 0x40001baf60, {ConnectivityState:IDLE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused""}"
2024/04/20 13:43:31 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to CONNECTING
"2024/04/20 13:43:31 INFO: [core] [Channel #1 SubChannel #2]Subchannel picks a new address ""10.0.27.158:50051"" to connect"
"2024/04/20 13:43:31 INFO: [core] [pick-first-lb 0x40001baed0] Received SubConn state update: 0x40001baf60, {ConnectivityState:CONNECTING ConnectionError:<nil>}"
"2024/04/20 13:43:31 INFO: [core] Creating new client transport to ""{Addr: \""10.0.27.158:50051\"", ServerName: \""server.grpc.local:50051\"", }"": connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:31 WARNING: [core] [Channel #1 SubChannel #2]grpc: addrConn.createTransport failed to connect to {Addr: ""10.0.27.158:50051"", ServerName: ""server.grpc.local:50051"", }. Err: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:31 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to TRANSIENT_FAILURE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:31 INFO: [core] [pick-first-lb 0x40001baed0] Received SubConn state update: 0x40001baf60, {ConnectivityState:TRANSIENT_FAILURE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused""}"
"2024/04/20 13:43:32 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to IDLE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:32 INFO: [core] [pick-first-lb 0x40001baed0] Received SubConn state update: 0x40001baf60, {ConnectivityState:IDLE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused""}"
2024/04/20 13:43:32 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to CONNECTING
"2024/04/20 13:43:32 INFO: [core] [Channel #1 SubChannel #2]Subchannel picks a new address ""10.0.27.158:50051"" to connect"
"2024/04/20 13:43:32 INFO: [core] [pick-first-lb 0x40001baed0] Received SubConn state update: 0x40001baf60, {ConnectivityState:CONNECTING ConnectionError:<nil>}"
"2024/04/20 13:43:32 INFO: [core] Creating new client transport to ""{Addr: \""10.0.27.158:50051\"", ServerName: \""server.grpc.local:50051\"", }"": connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:32 WARNING: [core] [Channel #1 SubChannel #2]grpc: addrConn.createTransport failed to connect to {Addr: ""10.0.27.158:50051"", ServerName: ""server.grpc.local:50051"", }. Err: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:32 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to TRANSIENT_FAILURE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:32 INFO: [core] [pick-first-lb 0x40001baed0] Received SubConn state update: 0x40001baf60, {ConnectivityState:TRANSIENT_FAILURE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused""}"
"2024/04/20 13:43:35 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to IDLE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:35 INFO: [core] [pick-first-lb 0x40001baed0] Received SubConn state update: 0x40001baf60, {ConnectivityState:IDLE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused""}"
2024/04/20 13:43:35 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to CONNECTING
"2024/04/20 13:43:35 INFO: [core] [Channel #1 SubChannel #2]Subchannel picks a new address ""10.0.27.158:50051"" to connect"
"2024/04/20 13:43:35 INFO: [core] [pick-first-lb 0x40001baed0] Received SubConn state update: 0x40001baf60, {ConnectivityState:CONNECTING ConnectionError:<nil>}"
"2024/04/20 13:43:35 INFO: [core] Creating new client transport to ""{Addr: \""10.0.27.158:50051\"", ServerName: \""server.grpc.local:50051\"", }"": connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:35 WARNING: [core] [Channel #1 SubChannel #2]grpc: addrConn.createTransport failed to connect to {Addr: ""10.0.27.158:50051"", ServerName: ""server.grpc.local:50051"", }. Err: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:35 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to TRANSIENT_FAILURE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:35 INFO: [core] [pick-first-lb 0x40001baed0] Received SubConn state update: 0x40001baf60, {ConnectivityState:TRANSIENT_FAILURE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused""}"
"2024/04/20 13:43:39 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to IDLE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:39 INFO: [core] [pick-first-lb 0x40001baed0] Received SubConn state update: 0x40001baf60, {ConnectivityState:IDLE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused""}"
2024/04/20 13:43:39 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to CONNECTING
"2024/04/20 13:43:39 INFO: [core] [Channel #1 SubChannel #2]Subchannel picks a new address ""10.0.27.158:50051"" to connect"
"2024/04/20 13:43:39 INFO: [core] [pick-first-lb 0x40001baed0] Received SubConn state update: 0x40001baf60, {ConnectivityState:CONNECTING ConnectionError:<nil>}"
"2024/04/20 13:43:39 INFO: [core] Creating new client transport to ""{Addr: \""10.0.27.158:50051\"", ServerName: \""server.grpc.local:50051\"", }"": connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:39 WARNING: [core] [Channel #1 SubChannel #2]grpc: addrConn.createTransport failed to connect to {Addr: ""10.0.27.158:50051"", ServerName: ""server.grpc.local:50051"", }. Err: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:39 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to TRANSIENT_FAILURE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:39 INFO: [core] [pick-first-lb 0x40001baed0] Received SubConn state update: 0x40001baf60, {ConnectivityState:TRANSIENT_FAILURE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused""}"
"2024/04/20 13:43:40 could not invoke: rpc error: code = DeadlineExceeded desc = latest balancer error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:46 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to IDLE, last error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
"2024/04/20 13:43:46 INFO: [core] [pick-first-lb 0x40001baed0] Received SubConn state update: 0x40001baf60, {ConnectivityState:IDLE ConnectionError:connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused""}"
2024/04/20 13:43:46 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to CONNECTING
"2024/04/20 13:43:46 INFO: [core] [Channel #1 SubChannel #2]Subchannel picks a new address ""10.0.27.158:50051"" to connect"
"2024/04/20 13:43:46 INFO: [core] [pick-first-lb 0x40001baed0] Received SubConn state update: 0x40001baf60, {ConnectivityState:CONNECTING ConnectionError:<nil>}"
"2024/04/20 13:43:51 could not invoke: rpc error: code = DeadlineExceeded desc = latest balancer error: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: connect: connection refused"""
2024/04/20 13:43:59 INFO: [core] [Channel #1]Resolver state updated: {
" ""Addresses"": ["
{
" ""Addr"": ""10.0.30.165:50051"","
" ""ServerName"": """","
" ""Attributes"": null,"
" ""BalancerAttributes"": null,"
" ""Metadata"": null"
}
" ],"
" ""Endpoints"": ["
{
" ""Addresses"": ["
{
" ""Addr"": ""10.0.30.165:50051"","
" ""ServerName"": """","
" ""Attributes"": null,"
" ""BalancerAttributes"": null,"
" ""Metadata"": null"
}
" ],"
" ""Attributes"": null"
}
" ],"
" ""ServiceConfig"": null,"
" ""Attributes"": null"
} ()
2024/04/20 13:43:59 INFO: [core] [pick-first-lb 0x40001baed0] Received new config {
" ""shuffleAddressList"": false"
"}, resolver state {"
" ""Addresses"": ["
{
" ""Addr"": ""10.0.30.165:50051"","
" ""ServerName"": """","
" ""Attributes"": null,"
" ""BalancerAttributes"": null,"
" ""Metadata"": null"
}
" ],"
" ""Endpoints"": ["
{
" ""Addresses"": ["
{
" ""Addr"": ""10.0.30.165:50051"","
" ""ServerName"": """","
" ""Attributes"": null,"
" ""BalancerAttributes"": null,"
" ""Metadata"": null"
}
" ],"
" ""Attributes"": null"
}
" ],"
" ""ServiceConfig"": null,"
" ""Attributes"": null"
}
2024/04/20 13:43:59 INFO: [core] [Channel #1 SubChannel #2]addrConn: updateAddrs curAddr: {
" ""Addr"": ""10.0.27.158:50051"","
" ""ServerName"": ""server.grpc.local:50051"","
" ""Attributes"": null,"
" ""BalancerAttributes"": null,"
" ""Metadata"": null"
"}, addrs: ["
{
" ""Addr"": ""10.0.30.165:50051"","
" ""ServerName"": """","
" ""Attributes"": null,"
" ""BalancerAttributes"": null,"
" ""Metadata"": null"
}
]
"2024/04/20 13:43:59 INFO: [core] Creating new client transport to ""{Addr: \""10.0.27.158:50051\"", ServerName: \""server.grpc.local:50051\"", }"": connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: operation was canceled"""
"2024/04/20 13:43:59 WARNING: [core] [Channel #1 SubChannel #2]grpc: addrConn.createTransport failed to connect to {Addr: ""10.0.27.158:50051"", ServerName: ""server.grpc.local:50051"", }. Err: connection error: desc = ""transport: Error while dialing: dial tcp 10.0.27.158:50051: operation was canceled"""
"2024/04/20 13:43:59 INFO: [core] [Channel #1 SubChannel #2]Subchannel picks a new address ""10.0.30.165:50051"" to connect"
2024/04/20 13:43:59 INFO: [core] [Channel #1 SubChannel #2]Subchannel Connectivity change to READY
"2024/04/20 13:43:59 INFO: [core] [pick-first-lb 0x40001baed0] Received SubConn state update: 0x40001baf60, {ConnectivityState:READY ConnectionError:<nil>}"
2024/04/20 13:43:59 INFO: [core] [Channel #1]Channel Connectivity change to READY
2024/04/20 13:44:00 hello
2024/04/20 13:44:01 hello
2024/04/20 13:44:02 hello
...