日記マン

動画広告プロダクトしてます。Go, Kubernetesが好きです。

Goのサーバサイドアプリケーションのパフォーマンス可視化に向けたメトリクス設計

最近はGoで書いたアプリケーションをKubernetesで運用し始めたが、
アプリケーションの内部状態を計測できるようにObservabilityの確保にトライしている。

「Observabilityがなぜ必要だと考えるか」について山口さんのエントリはとても学びになった。

ymotongpoo.hatenablog.com

顧客に対し、不便や不満のないようにサービスを提供できているか。
リソースの状態のみならずサービスの健康状態を表すアプリケーションレベルのメトリクスは、可観測性の確保において重要になる。
例えばHTTP応答レイテンシやエラー率などである。
Goならばメモリ管理がGCなのでランタイムレベルのメトリクスも重要になる。
例えばGCの発生頻度や実行レイテンシ。
これらをアプリケーションプロセス側がメトリクスを収集可能に実装することをInstrumentationと呼ぶ。

ではどのようなメトリクスを設計するか。
パフォーマンス分析に例えばUSEメソッドがある。
USEメソッドは Utilization(利用率), Saturation(飽和率) そして Errors(エラー数) の3系統の指標を用いてシステムの状態の分析する方法論である。

www.brendangregg.com

アプリケーションやランタイムレベルでもUSEメソッドに基づいたパフォーマンス分析ができるよう
指標を選択したInstrumentationを目標にする。

前提としてメトリクスの収集にPrometheusを使う。
PrometheusはDataDogやNewRelicなどの監視SaaSとは異なり、
自前でPrometheusサーバをホストしPull型モデルでメトリクスを収集する。
Pull型とは監視対象側がHTTPレスポンスとしてメトリクスを返すようにサービングし
Prometheusサーバが定期的に(ex. 15秒毎)HTTPリクエストしメトリクスをパース・収集する。

アプリケーションメトリクスの設計

Goアプリケーションにおいてポート :8080 で外部向けにアプリケーションを公開し、
ポート :8081 でメトリクスを公開する例が以下になる。

package main
 
func main() {
    r := chi.NewRouter()
    // ...
    appSrv := httputil.NewServer(":8080", r)
    metricsSrv := httputil.NewServer(":8081", promhttp.Handler())
}
package httputil
func NewServer(addr string, h http.Handler) *http.Server {
    srv := &http.Server{
        Addr: addr,
        Handler: h,
    }
 
    go func(){
        srv.ListenAndServe()
    }()
 
    return srv
}

Open Metricsフォーマットで公開する必要がある。
これは promhttp パッケージを使う。
promhttp.Handler() はデフォルトでGoランタイムのメトリクスコレクタがビルトインされている。

HTTP応答時間はテイルレイテンシ(高めのパーセンタイル値)を追う。
99なのか99.9なのか99.99なのか、どの値を指標にするか話し合う。

package metrics
 
var HTTPRequestDurationSeconds = prometheus.NewHistogramVec(prometheus.HistogramOpts{
    Namespace: "app",
    Name: "http_request_duration_seconds",
    Bucket: []float64{0.01, 0.05, 0.1, 0.5, 1, 5}
}, []string{"path", "code"})
package httputil

func InstrumentHTTPRequestDuration(next http.Handler) http.Handler {
    f := func(w http.ResponseWriter, r *http.Request) {
        ww := wrappedResponseWriter{w: w}
        start := time.Now()
        defer func() {
            elapsed := time.Since(start)
            metrics.HTTPRequestDurationSeconds.WithLabelValues(r.Method, r.URL.Path, strconv.Itoa(ww.statusCode)).Observe(elapsed.Seconds())
        }()
        next.ServeHTTP(ww, r)
    }
    return http.HandlerFunc(f)
}
func main() {
    r := chi.NewRouter()
    r.Use(httputil.InstrumentHTTPRequestDuration)
    // ...
}

HTTPハンドラをラップするmiddlewareとしてレイテンシの計測を実施する。

histogram_quantile(0.99, sum by(le, path, code) (rate(app_http_request_duration_seconds_bucket{}[5m])))

Histogramタイプのメトリックは histogram_quantile() 関数を使いパーセンタイル値を推定する。

sum (rate(app_http_request_duration_seconds_count{}[5m]))

Histogramタイプには回数の _count と合計値 _sum がある。
_count を用いてスループットとして秒間リクエストを表現できる。

package metrics

var HTTPRequestInFlight = prometheus.NewGauge(prometheus.GaugeOpts{
    Namespace: "app",
    Name:      "http_request_in_flight",
})
package httputil

func InstrumentHTTPRequestInflight(next http.Handler) http.Handler {
    f := func(w http.ResponseWriter, r *http.Request) {
        metrics.HTTPRequestInFlight.Inc()
        defer metrics.HTTPRequestInFlight.Dec()
        next.ServeHTTP(w, r)
    }
 
    return http.HandlerFunc(f)
}

Gaugeタイプとしてインフライト(処理中のリクエスト)もInstrumentationする。

sum (app_http_requests_in_flight{})

インフライトも可視化する。

IOレイテンシをそれぞれ用意する。
これによりどのアクセスが直接的にレイテンシに影響したかドリルダウンできるようになる。

コネクション待機を可視化する。
*sql.DB が提供する Stats.WaitDuration はオープンできるコネクションが全て利用中の状態の経過時間の加算値になる。
アプリ側でこれをカウンターとして定期的にセットし公開する。
先日エントリを書いた。

i101330.hatenablog.com

sum (rate(app_mysql_wait_duration_seconds_total{}[5m])

メトリクスタイプはGaugeだが経過時間の増加なのでrate()関数で秒間の増加度を導出する。
コネクションプールがサチってないか確認できる。

ランタイムレベル

ランタイムメトリクスとして promhttp.Handler() を利用する際にデフォルトでコレクタされる go_* メトリクスを扱う。
go_memstats_* はヒープオブジェクトのサイズなどを計測できる。

github.com

go_memstats_heap_alloc_bytes < go_memstats_last_gc_bytes の関係がある。

GC回数とGCレイテンシを可視化する。

rate(go_gc_duration_seconds_count{}[5m])

GoのGCタイミングは前回GC後のヒープオブジェクトサイズがx倍になった時である。
つまりメモリサイズの増加率が大きい場合GC回数は増える。
レイテンシ遅延の原因にGC回数が関係ありそうな場合GOGCの値を変更する。
メモリに余裕があるときはGOGCをデフォルトの100から400などに引き上げてGC実行回数を減らす。
ちなみにGoはGCレイテンシは0.5-1.5msecほどでCPU利用率は25%以内がSLOになる。

blog.golang.org

リソース

PodのCPU, Memory, Disk, NWといった各リソースの状態を計測する。

コンテナ運用の場合、cpu.cfs_quotaによるCPU利用制限を設けることが多い。
CPUコア数と同値のGOMAXPROCSではその分最低OSスレッド数を生成するが、
スレッドを増やすことによる多重化はクォータ制限と相反するのでGOMAXPROCSを制限値と同値ぐらいにする。

github.com

コンテナプロセスのリソースはcAdvisorを使う。
まずはPod別にCPU使用率を可視化する。

100 * sum by(pod_name) (sum by(container_name, pod_name) (rate(container_cpu_usage_seconds_total{id!="", container_name!~"|POD"}[2m])) / sum by(container_name, pod_name) (container_spec_cpu_quota{id!="", container_name!~"|POD"}/container_spec_cpu_period{id!="", container_name!~"|POD"}))

container_spec_cpu_quotacontainer_spec_cpu_period はそれぞれcgroupの cpu.cfs_quota_us , cpu.cfs_total_us を表す。
そのコンテナプロセスが1秒間に利用可能なCPUは container_spec_cpu_quota/cputainer_spec_cpu_period で表せる。
つまりKubernetesで宣言した limits.cpu と同値になる。
container_cpu_usage_seconds_total は秒単位の消費CPU時間になる。
これから秒間のCPU消費を求めるのは rate(container_cpu_usage_seconds_total[2m]) になる。
単位を合わせ100倍すればコンテナプロセスが利用可能なCPUのうちどれくらいの割合でCPUを消費したかを算出できる。

メモリは container_memory_working_set_bytes で現在の利用量を出力できる。
container_memory_usage_bytes はそのコンテナ(cgroup)が利用したメモリの合計になる。

まとめ

アプリケーションエンジニアにおいてObservabilityの確保は
サービスの信頼性向上の実現のために必要な取り組みになってきたと思う。
アプリケーション固有のカスタムメトリクスはもちろんランタイムメトリクスもしっかり出力して監視できる状態にする。
つづいて実際に負荷をかけてどの数値を追ってパフォーマンスチューニングするかといったエントリを書ければと思う。