Cloud Runで動くJVMの監視にログベースの指標が便利 - 株式会社ヘンリーエンジニアブログ

株式会社ヘンリーでSREをやっているTODA（@Kengo_TODA）です。弊社ではGoogle Cloud Platform（GCP）を活用してサービスを構築しており、またサーバサイドにはKotlinを利用しています。Cloud Runで動くJVMサービスの監視にログベースの指標が便利だったので紹介します。

何をもってJVMで駆動するサービスを「メモリが足りていない」と判断するか

Cloud Runのメモリ監視で最も利用しやすいのは、Cloud Monitoringでメモリ利用率などを見ることでしょう。次に示す図のように、サービスごとのデータを取ってグラフ化できます。

ではこのグラフから何がわかるのでしょうか？例えば下側に紫色で示されたCloud Runサービスはメモリにずいぶんと余裕がありそうです。常時この状態であれば、メモリ割当量を減らしても良さそうですね。

反面上側にオレンジ色で示されたCloud Runサービスは、だいぶメモリを使っています。しかし、これをもって「メモリが足りないので増やす」判断を下すことはできません。JVMで動いているサービスは、Javaヒープなどの領域がどのように使われているか・フルGCがどの程度生じているのかを分析して初めて「メモリが足りているかどうか」判断できるからです。

単にメモリの利用率だけを監視すると、むしろ理想的にメモリを活用できているサービスを”犯人”だとしてしまう可能性があります。実際弊社でもユーザ増加に起因するメモリ利用量増加によって、一部サービスが頻繁にアラートを投げるようになりました。

フルGCの回数を数える

それでは対象のCloud Runサービスで、どのくらいフルGCが実行されているのか数えてみましょう。

GCの発生回数を取得するには、まずGC実行記録をログを出すようにします。最新のJVMで必要な設定は久保田さんのUnified JVM Loggingに詳しく説明されていて、弊社では -Xlog:gc をJVM起動オプションに追加しました。この設定により、以下のようなログがCloud Loggingに出力されます：

[4204.610s][info][gc] GC(223) Pause Young (Allocation Failure) 139M->72M(247M) 4.592ms
[4077.128s][info][gc] GC(217) Pause Full (Allocation Failure) 176M->62M(250M) 302.523ms

こうしたログがあれば、grepやwcを組み合わせてフルGC回数を数えることはできそうに感じませんか？GCPの「ログベースの指標」はこうしたニーズの面倒を見てくれます。例えばTerraformなら以下のように設定すると、対象サービスのフルGC回数を数えられます:

resource "google_logging_metric" "full_gc" {
  name        = "${google_cloud_run_service.service.name}-full-gc"
  description = "The full GC (G1GC) triggered in the target JVM"
  filter = join(" AND ", [
    "resource.type=\"cloud_run_revision\"",
    "resource.labels.service_name=\"${google_cloud_run_service.service.name}\"",
    "textPayload:\"[gc]\"",
    "textPayload:\"Pause Full\"",
  ])
  metric_descriptor {
    metric_kind = "DELTA"
    value_type  = "INT64"
  }
}

更にMetrics Explorerを使うとグラフ化もできます。弊社の事例では、時間帯によってフルGCが生じているものの最頻値でも1分に1回程度であり、余裕はあると判断しました：

フルGCが頻繁に実行されたらSlackに通知を投げる

さて今は余裕があるとしても、今後負荷が増えてフルGCが増えてくる可能性もあります。よってフルGCの頻度が増えたらSlackに通知を投げるようにしておきましょう。これはCloud Monitoring Alertsによって実現できます。

今回はサービスごとのフルGC回数を数え、5分間に10回以上のフルGCが実行された場合にアラートを投げるようにしました。ケースによってはコンテナインスタンスごとにフルGCを数えても丁寧で良いと思います。

resource "google_monitoring_alert_policy" "full_gc" {
  display_name = "[${var.env}] Frequent Full GC (${google_cloud_run_service.service.name})"
  combiner     = "OR"
  conditions {
    display_name = "Full GCが5分間に10回以上実行されました。"
    condition_threshold {
      filter = join(" AND ", [
        "metric.type=\"logging.googleapis.com/user/${google_logging_metric.full_gc.name}\"",
        "resource.type=\"cloud_run_revision\""
      ])
      threshold_value = 9
      duration        = "300s"
      comparison      = "COMPARISON_GT"
      aggregations {
        alignment_period     = "60s"
        cross_series_reducer = "REDUCE_SUM"
        per_series_aligner   = "ALIGN_SUM"
      }
    }
  }

  notification_channels = [
    var.notification_channel,
  ]
}