Kotlin + gRPCでdropwizard/metricsをつかってメトリクスを取得してみた

今回のエントリはKotlin + gRPC（FWはSpringBoot 2.0.0.M1）のアプリケーションでgRPCのリクエストタイムやエラー回数などのメトリクスを計測する方法をまとめていく。

dropwizard/metrics

メトリクス計測のライブラリには dropwizard/metricsをつかってみた。

Getting Started | Metrics

gRPCリクエストのメトリクスを計測していきたいのでMetersとTimersを使い、gRPCリクエストのエラー回数とgRPCリクエストのレスポンスタイムをそれぞれ計測していく。

ログの出力形式にはSlf4jReporterを使って、メトリクスをログファイルへ出力していく。

gRPC Severにインタセプターを追加する

メトリクスの計測ポイントをつくるためにgRPC Serverのリクエストをインターセプトしたい。
io.grpc.ServerInterceptorを実装した MetricsInterceptorを準備してServerBuilderにgRPC Serverに追加するときにServerInterceptorも添えてあげるとよい。
コードとしては次のようになる。

MetricsInterceptor

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19

override fun <ReqT : Any?, RespT : Any?> interceptCall(call: ServerCall<ReqT, RespT>?, headers: Metadata?, next: ServerCallHandler<ReqT, RespT>?): ServerCall.Listener<ReqT> {

    val timer = metricRegistry.timer(metricName(REQUEST_TIME, call?.methodDescriptor?.fullMethodName!!.replace("/", "."))).time()

    val serverCall = object : ForwardingServerCall.SimpleForwardingServerCall<ReqT, RespT>(call) {

        override fun close(status: Status?, trailers: Metadata?) {
            val errorMeter = metricRegistry.meter(metricName(ERROR_METRIC, methodDescriptor.fullMethodName.replace("/", ".")))
            if (!status!!.isOk()) {
                errorMeter.mark()
                logger.error { "An error occured with %s".format(call.methodDescriptor) }
            }
            timer.stop()
            super.close(status, trailers)
        }
    }

    return next?.startCall(serverCall, headers)!!
}

SimpleForwardingServerCallクラスを実装し、 closeをoverrideしている。
ここでMetersとTimersのメトリクス計測ポイントを追加している。

ServerBuilderにgRPC Serverに追加するときにServerInterceptorも添えてあげる

1
2
3
4
5
6
7

getBeanNamesByTypeWithAnnotation(GRpcService::class).subscribe {
    name ->
    val server = applicationContext.beanFactory.getBean(name, BindableService::class) as BindableService
    val service = server.bindService()
    serverBuilder.addService(ServerInterceptors.intercept(service, metricsInterceptor))
    logger.info { "$name service has been registered." }
}

余談だが、１つのjarにHTTP ServerとgRPC Serverを載せられる便利なLogNet/grpc-spring-boot-starterというライブラリがある。
このライブラリはjava版でありSpringBoot 2.0.0.M1のバージョンでは動作保証されていないので、今回のエントリを期に参考にしながらKotlinで書き換えてみた。

メトリクスを見てみよう

ログの出力形式には[Slf4jReporter]をつかったので指定したログファイルにメトリクスが出力されていることが確認できた。

1
2

[2017-07-12 03:06:00.881] type=METER, name=server.error.messages.TaskService.GetTaskListService, count=0, mean_rate=0.0, m1=0.0, m5=0.0, m15=0.0, rate_unit=events/second
[2017-07-12 03:06:00.887] type=TIMER, name=server.request.time.messages.TaskService.GetTaskListService, count=5, min=9.169273, max=226.930993, mean=53.95158430282904, stddev=84.29036619882183, median=12.679804, p75=17.87868, p95=226.930993, p98=226.930993, p99=226.930993, p999=226.930993, mean_rate=0.008607979785884044, m1=5.629057078531829E-5, m5=0.11817160428031309, m15=0.4228910681867675, rate_unit=events/second, duration_unit=milliseconds

ログ出力は10分ごとに繰り返し行われるように設定した。

まとめ

コード

動くコードをgithubに置いているので参照してください。

今回の導入の差分もあります。他の修正内容も入っていて分かりづらいですが、よければどうぞ。

ADD grpc-metrics by nsoushi · Pull Request #7 · nsoushi/spring5-kotlin-application · GitHub