gRPCのChannelzを使ってみた

# Channelzとは

gRPCを使おうとして最初にはまるのがコネクションの扱いな気がします。HTTPでリクエストするのと違ってリクエストとコネクションの管理が独立しているのでTransient Failureってなんや！ということが一回はあると思います。更にLoad BalancingしているとgRPCのコード上のコネクション(grpc.ClientConn)が複数のサーバへのコネクションを束ねている状態になるのでもっと複雑になります。

Transient failureなどの状態についての詳細はこちら。
https://github.com/grpc/grpc/blob/master/doc/connectivity-semantics-and-api.md

そこで様々なコネクションの状態を観測できるようにしようということでChannelzというものが提案された(既にマージ済み)。
https://github.com/grpc/proposal/blob/master/A14-channelz.md

これ自体は軽く読んでよくわからんという気持ちになったけど、grpc-goにもchannelzの実装が入ったので試してみる。

## Channelz Service

Channelzの状態を外から観測できるようにgRPCのサービスとして定義したものでprotoになっている。

https://github.com/grpc/grpc-proto/blob/master/grpc/channelz/v1/channelz.proto


```proto
// Channelz is a service exposed by gRPC servers that provides detailed debug
// information.
service Channelz {
  // Gets all root channels (i.e. channels the application has directly
  // created). This does not include subchannels nor non-top level channels.
  rpc GetTopChannels(GetTopChannelsRequest) returns (GetTopChannelsResponse);
  // Gets all servers that exist in the process.
  rpc GetServers(GetServersRequest) returns (GetServersResponse);
  // Gets all server sockets that exist in the process.
  rpc GetServerSockets(GetServerSocketsRequest) returns (GetServerSocketsResponse);
  // Returns a single Channel, or else a NOT_FOUND code.
  rpc GetChannel(GetChannelRequest) returns (GetChannelResponse);
  // Returns a single Subchannel, or else a NOT_FOUND code.
  rpc GetSubchannel(GetSubchannelRequest) returns (GetSubchannelResponse);
  // Returns a single Socket or else a NOT_FOUND code.
  rpc GetSocket(GetSocketRequest) returns (GetSocketResponse);
}
```


## テストコード

使ったコードはここにおいてます
https://github.com/kazegusuri/grpc-channelz-test

### main

* `grpc.RegisterChannelz()` で有効にする必要があります
   * 有効にしないとセグフォします
* `channelzsvc.RegisterChannelzServiceToServer()`でサービスを登録 

```go
package main

import (
	"context"
	"log"
	"net"
	"time"

	"github.com/k0kubun/pp"
	"github.com/kazegusuri/grpc-channelz-test/pb"
	"google.golang.org/grpc"
	channelzsvc "google.golang.org/grpc/channelz/service"
	"google.golang.org/grpc/reflection"
)

var (
	cli1 pb.EchoClient
	cli2 pb.EchoClient
)

func init() {
	grpc.RegisterChannelz()
}

func main() {
	ctx := context.Background()
	conn1, err := grpc.DialContext(ctx, "127.0.0.1:9000", grpc.WithInsecure())
	if err != nil {
		log.Fatalf("grpc.DialContext failed: %v", err)
	}
	defer func() { _ = conn1.Close() }()

	conn2, err := grpc.DialContext(ctx, "127.0.0.1:9000", grpc.WithInsecure())
	if err != nil {
		log.Fatalf("grpc.DialContext failed: %v", err)
	}
	defer func() { _ = conn2.Close() }()

	cli1 = pb.NewEchoClient(conn1)
	cli2 = pb.NewEchoClient(conn2)

	go func() {
		for {
			time.Sleep(3 * time.Second)
			_, err := cli1.Echo(ctx, &pb.EchoMessage{Message: "hello"})
			if err != nil {
				log.Printf("goroutine: echo failed: %v", err)
			} else {
				log.Printf("goroutine: echo succeeded")
			}
		}
	}()

	server := newServer()
	s := grpc.NewServer()
	pb.RegisterEchoServer(s, server)
	reflection.Register(s)
	channelzsvc.RegisterChannelzServiceToServer(s)

	lis, err := net.Listen("tcp", ":8000")
	if err != nil {
		log.Fatalf("failed to listen: %v", err)
	}

	if err := s.Serve(lis); err != nil {
		log.Fatalf("err %v\n", err)
	}

	select {}
}
```

### sub

* mainサーバーから接続するためのsubサーバー
* 大したことしていないので省略
    * https://github.com/kazegusuri/grpc-channelz-test/blob/master/sub/main.go


## Channels

ここではGetTopChannelsだけ使います
GetChannelやGetSubChannelは似たような情報なので

### GetTopChannels

#### 起動直後

* channelsが2つある
   * この2つがserverからsubに接続しているconn1とconn2だと思われる
* stateが `READY`になっている
* goroutineで定期的に実行しているので`calls_started`/`calls_succeeded`が増えていく
* channel.ref.nameはgrpc.DialContextの引数で指定したtargetの値が入る

```bash
$ echo '{}' | grpcurl call -k localhost:8000 grpc.channelz.v1.Channelz.GetTopChannels | jq .
{
  "channel": [
    {
      "ref": {
        "channel_id": 1,
        "name": "127.0.0.1:9000"
      },
      "data": {
        "state": {
          "state": "READY"
        },
        "target": "127.0.0.1:9000",
        "trace": null,
        "calls_started": 1,
        "calls_succeeded": 1,
        "calls_failed": 0,
        "last_call_started_timestamp": "2018-06-23T10:30:36.713166503Z"
      },
      "channel_ref": [],
      "subchannel_ref": [
        {
          "subchannel_id": 5,
          "name": ""
        }
      ],
      "socket_ref": []
    },
    {
      "ref": {
        "channel_id": 2,
        "name": "127.0.0.1:9000"
      },
      "data": {
        "state": {
          "state": "READY"
        },
        "target": "127.0.0.1:9000",
        "trace": null,
        "calls_started": 0,
        "calls_succeeded": 0,
        "calls_failed": 0,
        "last_call_started_timestamp": "0001-01-01T00:00:00.000Z"
      },
      "channel_ref": [],
      "subchannel_ref": [
        {
          "subchannel_id": 6,
          "name": ""
        }
      ],
      "socket_ref": []
    }
  ],
  "end": true
}
```

#### subを落としてみる

* subを落とした直後からstateが`TRANSIENT_FAILURE`になった

```bash
$ echo '{}' | grpcurl call -k localhost:8000 grpc.channelz.v1.Channelz.GetTopChannels | jq .
{
  "channel": [
    {
      "ref": {
        "channel_id": 1,
        "name": "127.0.0.1:9000"
      },
      "data": {
        "state": {
          "state": "TRANSIENT_FAILURE"
        },
        "target": "127.0.0.1:9000",
        "trace": null,
        "calls_started": 55,
        "calls_succeeded": 54,
        "calls_failed": 1,
        "last_call_started_timestamp": "2018-06-23T10:34:12.792971011Z"
      },
      "channel_ref": [],
      "subchannel_ref": [
        {
          "subchannel_id": 5,
          "name": ""
        }
      ],
      "socket_ref": []
    },
    {
      "ref": {
        "channel_id": 2,
        "name": "127.0.0.1:9000"
      },
      "data": {
        "state": {
          "state": "TRANSIENT_FAILURE"
        },
        "target": "127.0.0.1:9000",
        "trace": null,
        "calls_started": 0,
        "calls_succeeded": 0,
        "calls_failed": 0,
        "last_call_started_timestamp": "0001-01-01T00:00:00.000Z"
      },
      "channel_ref": [],
      "subchannel_ref": [
        {
          "subchannel_id": 6,
          "name": ""
        }
      ],
      "socket_ref": []
    }
  ],
  "end": true
}
```

#### subを復活させる

* 直後はまだstateは `TRANSIENT_FAILURE`のまま
   * この間にリクエストがあっても全て失敗になる
   * grpc.CallOptionの`FailFast(false)`にするとREADYになるまでブロッキングする
* しばらく経つとstateが `READY` になる
   * リクエストがあったからといって接続しにいくわけではなくgprc.DialOptionのBackoffの設定次第のはず
   * デフォルトではExponentialBackoffなので落ちている時間に応じて接続間隔がながくなる
      * 最大2分間隔
   
### まとめ

* TopChannelsでは全てのgrpc connectionの状態がわかる
* 試していないけどLoad Balancerを使っている場合でもsubchannelで確認できそう

## ServerとSocket

### GetServers

* server.ref.nameは今のところは空固定で設定できない

```bash
$ echo '{}' | grpcurl call -k localhost:8000 grpc.channelz.v1.Channelz.GetServers | jq .
{
  "server": [
    {
      "ref": {
        "server_id": 3,
        "name": ""
      },
      "data": {
        "trace": null,
        "calls_started": 30,
        "calls_succeeded": 14,
        "calls_failed": 14,
        "last_call_started_timestamp": "2018-06-23T11:31:33.324310565Z"
      },
      "listen_socket": [
        {
          "socket_id": 4,
          "name": ""
        }
      ]
    }
  ],
  "end": true
}
```

### GetServerSockets

Socketの参照の一覧が取れるだけで詳細自体はとれない

```bash
$ echo '{"server_id": 3}' | grpcurl call -k localhost:8000 grpc.channelz.v1.Channelz.GetServerSockets | jq .
{
  "socket_ref": [
    {
      "socket_id": 22,
      "name": ""
    }
  ],
  "end": true
}
```

### GetSocket

nullになるのはまだ実装されてないからかな。
https://github.com/grpc/grpc-go/pull/2149 がマージされたらもっと情報が増えるはず

```bash
$ echo '{"socket_id": 23}' | grpcurl call -k localhost:8000 grpc.channelz.v1.Channelz.GetSocket | jq .
{
  "socket": null
}
```

## まとめ

* デバッグなどに必要な情報が含まれていてそう
   * コネクション毎にstateが確認できる
* 現状ではまだツールがないので確認するのがかなり面倒
   * 誰かがtopみたいなCLIやdashboardのようなweb上で確認できるものを作るでしょう
* reflectionと同様にデバッグ用ポートみたいなものを作って提供するのが主流になるかも