理系学生日記

おまえはいつまで学生気分なのか

node.js の gRPC clientで client side keep-alive (定期的な PING frame 送出)を実現する

gRPC では HTTP/2 を使っており、HTTP/2 では 1 本の TCP のコネクションの上で stream を多重化します。このため、TCP のコネクションはずっと張りっぱなしになることが多く、どのようにしてこのコネクションを維持するかが重要な場合があります。

問題となり得るのは、コネクションに何のデータも流さない時間が長いときです。これは、peer 間の間に介在するネットワーク機器が、idle なコネクションを切断するときがあるときに問題になります。

1 サービスの都合で介在するネットワーク機器のすべてて idle timeout 設定を変更するのは困難なことも多い。こういった場合、「パケットを流さない connection が切断されるなら定期的にデータを流せばいいじゃん」という形で、定期的にパケットを流す仕組みが keepalive です。 gRPC の keepalive においては、定期的に HTTP/2 の PING frame を送信します。つまり、keepalive を明示的に設定することで、この idle timeout の問題を解決する事が可能です。

今回、node.js の gRPC 実装を使って keepalive を使おうとしたところ、本当に困難を極めたので、step-by-step で苦労の歴史を記録しておきます。

まずはドキュメントを確認する

client 側で keepalive するときの gRFC (仕様)です。 各言語の仕様を統一するためだと思うのですが、gRPC の仕様は gRFC として定義しているようです。ただ、言語仕様の統一状況は微妙でして、例えばこの client side keepalive は、C, Java, Go でしか実装されていないように読める。

Implemented in: C, Java, Go Last updated: 2017-03-31

こちらは、keepalive に必要な設定値のデフォルトだったり、簡単な FAQ をまとめたもの。 設定値のキーは、node.js だとそのままは使えません。上記ページの設定キーと、node.js 上での設定キーのマッピングは、grpc core の C 実装 (grpc_types.h)を見ればわかります(ヒドい…)

まずは gRPC クライアント

node.js では、grpc パッケージを使うのがスタンダードな gRPC の利用方法だと思います。ここでは、idle なコネクションを作りやすくするために、Server Streaming RPC である SayHellos RPC を呼び出すだけです。 シンプルにつかえて良いですね。

const path = require("path")
const grpc = require("grpc")
const protoLoader = require("@grpc/proto-loader")
const PROTO_PATH = path.join(__dirname, "greeter.proto")

try {
    const packageDefinition = protoLoader.loadSync(PROTO_PATH, {
        keepCase: false,
        longs: String,
        enums: String,
        defaults: true,
        oneofs: true
    })
    const greeter = grpc.loadPackageDefinition(packageDefinition).Greeter
    const client = new greeter(
        "localhost:50050",
        grpc.credentials.createInsecure()
    )
    const call = client.SayHellos({ name: "kiririmode" })
    call.on("data", data => {
        console.log("data: " + JSON.stringify(data))
    })
    call.on("end", () => {
        console.log("end")
    })
    call.on("error", e => {
        console.log(e)
    })
    call.on("status", status => {
        console.log("status: " + JSON.stringify(status))
    })
} catch (ex) {
    console.error(ex)
}

keepalive の有効化

gRPC の keepalive はデフォルト無効ですから、有効化しなければいけません。 しかし、このあたり、調べる限り現時点でドキュメントがない。結局、grpc-node の issue のコメントで設定方法がわかりました。

keepalive 関連の設定を入れるのは、client を作るときの第三引数のようなので、設定してみます。設定したのは、 grpc.keepalive_time_msgrpc.keepalive_timeout_ms の 2 つ。 keepalive_time_ms の方は、PING frame の送出間隔(ミリ秒)、keepalive_timeout_ms は PING frame 送出後に「応答が返ってこない」と判断する timeout 時間 (ミリ秒)の設定します。応答が返ってこないと判断すると、gRPC では connection を切断します。

    const client = new greeter(
        "localhost:50050",
        grpc.credentials.createInsecure(),
        {
            "grpc.keepalive_time_ms": 1000,
            "grpc.keepalive_timeout_ms": 2000
        }
    )

しかし PING が飛ばない。

上記のとおり設定して動かしましたが、PING frame がサーバには飛びません。 これは、HTTP/2 層の設定値の制限によるもののようです。

grpc.http2.min_time_between_pings_ms (GRPC_ARG_HTTP2_MIN_SENT_PING_INTERVAL_WITHOUT_DATA_MS の設定キー。デフォルトだと 300000 (5分))を設定すると、PING frame が飛ぶようになりました。この設定値は、HTTP/2 層における PING frame 送出の最小間隔を定義するものです。 おそらく、いくら grpc.keepalive_tims_ms を小さく指定しても、それが grpc.http2.min_time_between_pings_ms の制限値は超えられない、ということでしょうか。

    const client = new greeter(
        "localhost:50050",
        grpc.credentials.createInsecure(),
        {
            "grpc.keepalive_time_ms": 1000,
            "grpc.keepalive_timeout_ms": 2000,
            "grpc.http2.min_time_between_pings_ms": 3000
        }
    )

gRPC サーバ側のログを見ても、指定した 3 秒間隔で PING を受信できていることがわかります。

2019/05/12 08:18:25 http2: Framer 0xc000228000: read SETTINGS flags=ACK len=0
2019/05/12 08:18:28 http2: Framer 0xc000228000: read PING len=8 ping="\x00\x00\x00\x00\x00\x00\x00\x01"
2019/05/12 08:18:28 http2: Framer 0xc000228000: wrote PING flags=ACK len=8 ping="\x00\x00\x00\x00\x00\x00\x00\x01"
2019/05/12 08:18:31 http2: Framer 0xc000228000: read PING len=8 ping="\x00\x00\x00\x00\x00\x00\x00\x02"
2019/05/12 08:18:31 http2: Framer 0xc000228000: wrote PING flags=ACK len=8 ping="\x00\x00\x00\x00\x00\x00\x00\x02"

PING frame が 2 回しか飛ばない

しかし、2 回だけしかサーバは PING を受け取れていません (これ以降、PING frame の受信はありません)。これはなぜか。

2 回だけしか PING が送られていないのは、そういう設定になっているからです。 これは、grpc.http2.max_pings_without_data (GRPC_ARG_HTTP2_MAX_PINGS_WITHOUT_DATA) の設定によるもので、「データが送られていない場合の、PING frame 送出回数」を意味します。デフォルトが 2 なので、2 回しか PING frame が送出されていないってことですね。

この値を 0 にすると、この最大回数の制約を除去することができます。

    const client = new greeter(
        "localhost:50050",
        grpc.credentials.createInsecure(),
        {
            "grpc.keepalive_time_ms": 1000,
            "grpc.keepalive_timeout_ms": 2000,
            "grpc.http2.min_time_between_pings_ms": 3000,
            "grpc.http2.max_pings_without_data": 0
        }
    )

Error: 14 UNAVAILABLE: GOAWAY received でコネクションが切断される

しかし、この設定値でクライアントを動かすと、なんとサーバから error code 14 (UNAVAILABLE) とともにコネクションを切断されてしまいました。返却されたステータスは、status: {"code":14,"details":"GOAWAY received","metadata":{"_internal_repr":{}}} です。

サーバ側のログを見ると、ErrCode=ENHANCE_YOUR_CALM Debug="too_many_pings" といった記述があります。

ERROR: 2019/05/12 08:26:07 transport: Got too many pings from the client, closing the connection.
2019/05/12 08:26:07 http2: Framer 0xc0002400e0: wrote GOAWAY len=22 LastStreamID=1 ErrCode=ENHANCE_YOUR_CALM Debug="too_many_pings"
ERROR: 2019/05/12 08:26:07 transport: loopyWriter.run returning. Err: transport: Connection closing
WARNING: 2019/05/12 08:26:07 transport: http2Server.HandleStreams failed to read frame: read tcp [::1]:50050->[::1]:54447: use of closed network connection

この仕様については gRFC の方に記載があります。大量のクライアント接続が想定される gRPC サーバにとって、短期間で大量の PING frame が送出されるのは DoS attack にほかなりません。このため、頻度の短い PING frame を受信すると、サーバサイドから当該コネクションを切断するという挙動が定められています。

Servers need to respond to misbehaving clients by sending GOAWAY with error code ENHANCE_YOUR_CALM and additional debug data of ASCII "too_many_pings" followed by immediately closing the connection.

これはサーバ側で gRPC を設定することで回避が可能です。 golang の gRPC サーバの場合、keepalive.EnforcementPolicyMinTime を設定することになります。デフォルトは 5 分です。

本番環境では望ましい設定ではありませんが、今回は以下のように設定しました。

   s := grpc.NewServer(
        grpc.KeepaliveEnforcementPolicy(keepalive.EnforcementPolicy{
            MinTime: 2 * time.Second,
            PermitWithoutStream: true,
        }))

これにより、client side の keepalive が実現できました。

2019/05/12 08:52:43 http2: Framer 0xc0001bc000: read PING len=8 ping="\x00\x00\x00\x00\x00\x00\x00\x01"
2019/05/12 08:52:43 http2: Framer 0xc0001bc000: wrote PING flags=ACK len=8 ping="\x00\x00\x00\x00\x00\x00\x00\x01"
2019/05/12 08:52:46 http2: Framer 0xc0001bc000: read PING len=8 ping="\x00\x00\x00\x00\x00\x00\x00\x02"
2019/05/12 08:52:46 http2: Framer 0xc0001bc000: wrote PING flags=ACK len=8 ping="\x00\x00\x00\x00\x00\x00\x00\x02"
2019/05/12 08:52:49 http2: Framer 0xc0001bc000: read PING len=8 ping="\x00\x00\x00\x00\x00\x00\x00\x03"
2019/05/12 08:52:49 http2: Framer 0xc0001bc000: wrote PING flags=ACK len=8 ping="\x00\x00\x00\x00\x00\x00\x00\x03"
2019/05/12 08:52:52 http2: Framer 0xc0001bc000: read PING len=8 ping="\x00\x00\x00\x00\x00\x00\x00\x04"
2019/05/12 08:52:52 http2: Framer 0xc0001bc000: wrote PING flags=ACK len=8 ping="\x00\x00\x00\x00\x00\x00\x00\x04"
2019/05/12 08:52:55 http2: Framer 0xc0001bc000: read PING len=8 ping="\x00\x00\x00\x00\x00\x00\x00\x05"
2019/05/12 08:52:55 http2: Framer 0xc0001bc000: wrote PING flags=ACK len=8 ping="\x00\x00\x00\x00\x00\x00\x00\x05"
2019/05/12 08:52:58 http2: Framer 0xc0001bc000: read PING len=8 ping="\x00\x00\x00\x00\x00\x00\x00\x06"
2019/05/12 08:52:58 http2: Framer 0xc0001bc000: wrote PING flags=ACK len=8 ping="\x00\x00\x00\x00\x00\x00\x00\x06"
2019/05/12 08:53:01 http2: Framer 0xc0001bc000: read PING len=8 ping="\x00\x00\x00\x00\x00\x00\x00\a"
2019/05/12 08:53:01 http2: Framer 0xc0001bc000: wrote PING flags=ACK len=8 ping="\x00\x00\x00\x00\x00\x00\x00\a"