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を入れている

Go

package 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"をリクエストしレスポンスを出力する
これを一定数繰り返す

Go

package 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
...