LoginSignup
0
0
@eyasy1217(Takato Fukui)

grpc-go Wait-for-Readyを使いECS rolling updateでダウンタイム発生しにくくなることを検証

Last updated at Posted at 2024-04-22

ECSサービスへgRPCリクエスト中にECSサービスを更新するとダウンタイムが発生する
Wait-for-Readyを使うことでダウンタイムが発生しにくくなることを検証する

検証する環境と方法

aws構成

クライアントはAWS Cloud MapのDNSを使用してサーバー側ECSタスクを名前解決する
image.png
以下各サービスの設定値

  • 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
...
0
0
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
0
0