QuarkusアプリのメトリクスをMicrometer+Prometeus+Grafanaで可視化する

はじめに

Quarkus 1.9のリリースブログをなんとなく眺めていると以下のようなことが書かれていました。

Micrometer extension maturing

1.8 introduced a new Micrometer extension. During the 1.9 development cycle, it matured a lot and is now the recommended way to collect metrics in Quarkus.

原文リンク

どうやら1.9以降はMicrometerがメトリクスの収集方法としておすすめされるようなので、使ってみてPromethus+Grafanaで可視化するのをやってみようかと思います。 PrometeusとGrafanaはDocker使って立ち上げて、ホストにポートフォワードします。
あと、ついでにQuarkusで設定できるMicrometerの設定をまとめておこうと思います。

やってみる

環境

動作環境は以下の通り

$ java --version
openjdk 11.0.8 2020-07-14
OpenJDK Runtime Environment 18.9 (build 11.0.8+10)
OpenJDK 64-Bit Server VM 18.9 (build 11.0.8+10, mixed mode)


$ mvn --version
Apache Maven 3.6.3
Maven home: /usr/share/maven
Java version: 11.0.8, vendor: N/A, runtime: /home/someone/.sdkman/candidates/java/11.0.8-open
Default locale: ja_JP, platform encoding: UTF-8
OS name: "linux", version: "5.4.0-52-generic", arch: "amd64", family: "unix"


$ uname -srvmpio
Linux 5.4.0-52-generic #57-Ubuntu SMP Thu Oct 15 10:57:00 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux


$ lsb_release -a
LSB Version:    core-11.1.0ubuntu2-noarch:security-11.1.0ubuntu2-noarch
Distributor ID: Ubuntu
Description:    Ubuntu 20.04.1 LTS
Release:    20.04
Codename:   focal


$ docker version
Client: Docker Engine - Community
 Version:           19.03.12
 API version:       1.40
 Go version:        go1.13.10
 Git commit:        48a66213fe
 Built:             Mon Jun 22 15:45:36 2020
 OS/Arch:           linux/amd64
 Experimental:      false

Server: Docker Engine - Community
 Engine:
  Version:          19.03.12
  API version:      1.40 (minimum version 1.12)
  Go version:       go1.13.10
  Git commit:       48a66213fe
  Built:            Mon Jun 22 15:44:07 2020
  OS/Arch:          linux/amd64
  Experimental:     false
 containerd:
  Version:          1.2.13
  GitCommit:        7ad184331fa3e55e52b890ea95e65ba581ae3429
 runc:
  Version:          1.0.0-rc10
  GitCommit:        dc9208a3303feef5b3839f4323d9beb36df0a9dd
 docker-init:
  Version:          0.18.0

プロジェクトを作成する

Quarkus - Start coding with code.quarkus.ioでプロジェクトを作成します。
設定は以下の通り。

f:id:yuya_hirooka:20201104205319p:plain

ブログではMicroProfile Metricsじゃなくて、Micrometerの方を押してたきがしますがここではExperimentalってなってますね。
多分まだ修正されてないだけなんでしょうか。

pomにPrometheusの依存を追加しておく

MicromerterでPrometheusの形式の情報を取得するために以下の依存を追加しておく必要があります。

<dependency>
    <groupId>io.micrometer</groupId>
    <artifactId>micrometer-registry-prometheus</artifactId>
</dependency>

cURLでメトリクスを取得する

この状態ですでにメトリクスは取得できます。

アプリを起動して、cURLlocalhost:8080/metrics/を叩いてみます。

$ ./mvnw clean compile quarkus:dev

$ curl localhost:8080/metrics/
# HELP jvm_threads_states_threads The current number of threads having NEW state
# TYPE jvm_threads_states_threads gauge
jvm_threads_states_threads{state="runnable",} 20.0
jvm_threads_states_threads{state="blocked",} 0.0
jvm_threads_states_threads{state="waiting",} 10.0
jvm_threads_states_threads{state="timed-waiting",} 5.0
jvm_threads_states_threads{state="new",} 0.0
jvm_threads_states_threads{state="terminated",} 0.0
# HELP jvm_gc_memory_promoted_bytes_total Count of positive increases in the size of the old generation memory pool before GC to after GC
# TYPE jvm_gc_memory_promoted_bytes_total counter
jvm_gc_memory_promoted_bytes_total 0.0
# HELP jvm_gc_memory_allocated_bytes_total Incremented for an increase in the size of the young generation memory pool after one GC to before the next
# TYPE jvm_gc_memory_allocated_bytes_total counter
jvm_gc_memory_allocated_bytes_total 5.8720256E7
# HELP jvm_gc_overhead_percent An approximation of the percent of CPU time used by GC activities over the last lookback period or since monitoring began, whichever is shorter, in the range [0..1]
# TYPE jvm_gc_overhead_percent gauge
jvm_gc_overhead_percent 0.0014644940855901103
# HELP process_cpu_usage The "recent cpu usage" for the Java Virtual Machine process
# TYPE process_cpu_usage gauge
process_cpu_usage 1.0287248248851947E-4
# HELP system_cpu_usage The "recent cpu usage" for the whole system
# TYPE system_cpu_usage gauge
system_cpu_usage 0.13014392884149495
# HELP process_uptime_seconds The uptime of the Java virtual machine
# TYPE process_uptime_seconds gauge
process_uptime_seconds 7.019
# HELP process_start_time_seconds Start time of the process since unix epoch.
# TYPE process_start_time_seconds gauge
process_start_time_seconds 1.604492368312E9
# HELP jvm_info_total JVM version info
# TYPE jvm_info_total counter
jvm_info_total{runtime="OpenJDK Runtime Environment",vendor="Oracle Corporation",version="11.0.8+10",} 1.0
# HELP jvm_buffer_count_buffers An estimate of the number of buffers in the pool
# TYPE jvm_buffer_count_buffers gauge
jvm_buffer_count_buffers{id="mapped",} 0.0
jvm_buffer_count_buffers{id="direct",} 11.0
# HELP jvm_buffer_memory_used_bytes An estimate of the memory that the Java virtual machine is using for this buffer pool
# TYPE jvm_buffer_memory_used_bytes gauge
jvm_buffer_memory_used_bytes{id="mapped",} 0.0
jvm_buffer_memory_used_bytes{id="direct",} 21370.0
# HELP process_files_max_files The maximum file descriptor count
# TYPE process_files_max_files gauge
process_files_max_files 1048576.0
# HELP jvm_gc_pause_seconds Time spent in GC pause
# TYPE jvm_gc_pause_seconds summary
jvm_gc_pause_seconds_count{action="end of minor GC",cause="Metadata GC Threshold",} 1.0
jvm_gc_pause_seconds_sum{action="end of minor GC",cause="Metadata GC Threshold",} 0.007
# HELP jvm_gc_pause_seconds_max Time spent in GC pause
# TYPE jvm_gc_pause_seconds_max gauge
jvm_gc_pause_seconds_max{action="end of minor GC",cause="Metadata GC Threshold",} 0.007
# HELP jvm_memory_committed_bytes The amount of memory in bytes that is committed for the Java virtual machine to use
# TYPE jvm_memory_committed_bytes gauge
jvm_memory_committed_bytes{area="heap",id="G1 Survivor Space",} 8388608.0
jvm_memory_committed_bytes{area="heap",id="G1 Old Gen",} 2.07618048E8
jvm_memory_committed_bytes{area="nonheap",id="Metaspace",} 3.9010304E7
jvm_memory_committed_bytes{area="nonheap",id="CodeHeap 'non-nmethods'",} 2555904.0
jvm_memory_committed_bytes{area="heap",id="G1 Eden Space",} 3.0408704E8
jvm_memory_committed_bytes{area="nonheap",id="Compressed Class Space",} 4980736.0
jvm_memory_committed_bytes{area="nonheap",id="CodeHeap 'non-profiled nmethods'",} 8716288.0
# HELP system_load_average_1m The sum of the number of runnable entities queued to available processors and the number of runnable entities running on the available processors averaged over a period of time
# TYPE system_load_average_1m gauge
system_load_average_1m 1.11
# HELP jvm_gc_live_data_size_bytes Size of old generation memory pool after a full GC
# TYPE jvm_gc_live_data_size_bytes gauge
jvm_gc_live_data_size_bytes 1.2500864E7
# HELP jvm_memory_used_bytes The amount of used memory
# TYPE jvm_memory_used_bytes gauge
jvm_memory_used_bytes{area="heap",id="G1 Survivor Space",} 8388608.0
jvm_memory_used_bytes{area="heap",id="G1 Old Gen",} 1.0403712E7
jvm_memory_used_bytes{area="nonheap",id="Metaspace",} 3.7437216E7
jvm_memory_used_bytes{area="nonheap",id="CodeHeap 'non-nmethods'",} 1258624.0
jvm_memory_used_bytes{area="heap",id="G1 Eden Space",} 6291456.0
jvm_memory_used_bytes{area="nonheap",id="Compressed Class Space",} 4416816.0
jvm_memory_used_bytes{area="nonheap",id="CodeHeap 'non-profiled nmethods'",} 8708736.0
# HELP jvm_classes_loaded_classes The number of classes that are currently loaded in the Java virtual machine
# TYPE jvm_classes_loaded_classes gauge
jvm_classes_loaded_classes 6538.0
# HELP jvm_classes_unloaded_classes_total The total number of classes unloaded since the Java virtual machine has started execution
# TYPE jvm_classes_unloaded_classes_total counter
jvm_classes_unloaded_classes_total 0.0
# HELP http_server_connections_seconds_max  
# TYPE http_server_connections_seconds_max gauge
http_server_connections_seconds_max 0.016392673
# HELP http_server_connections_seconds  
# TYPE http_server_connections_seconds summary
http_server_connections_seconds_active_count 1.0
http_server_connections_seconds_duration_sum 0.016127428
# HELP jvm_gc_max_data_size_bytes Max size of old generation memory pool
# TYPE jvm_gc_max_data_size_bytes gauge
jvm_gc_max_data_size_bytes 8.321499136E9
# HELP jvm_buffer_total_capacity_bytes An estimate of the total capacity of the buffers in this pool
# TYPE jvm_buffer_total_capacity_bytes gauge
jvm_buffer_total_capacity_bytes{id="mapped",} 0.0
jvm_buffer_total_capacity_bytes{id="direct",} 21368.0
# HELP jvm_memory_max_bytes The maximum amount of memory in bytes that can be used for memory management
# TYPE jvm_memory_max_bytes gauge
jvm_memory_max_bytes{area="heap",id="G1 Survivor Space",} -1.0
jvm_memory_max_bytes{area="heap",id="G1 Old Gen",} 8.321499136E9
jvm_memory_max_bytes{area="nonheap",id="Metaspace",} -1.0
jvm_memory_max_bytes{area="nonheap",id="CodeHeap 'non-nmethods'",} 7553024.0
jvm_memory_max_bytes{area="heap",id="G1 Eden Space",} -1.0
jvm_memory_max_bytes{area="nonheap",id="Compressed Class Space",} 1.073741824E9
jvm_memory_max_bytes{area="nonheap",id="CodeHeap 'non-profiled nmethods'",} 2.44105216E8
# HELP process_files_open_files The open file descriptor count
# TYPE process_files_open_files gauge
process_files_open_files 212.0
# HELP jvm_threads_daemon_threads The current number of live daemon threads
# TYPE jvm_threads_daemon_threads gauge
jvm_threads_daemon_threads 13.0
# HELP jvm_threads_peak_threads The peak live thread count since the Java virtual machine started or peak was reset
# TYPE jvm_threads_peak_threads gauge
jvm_threads_peak_threads 42.0
# HELP jvm_threads_live_threads The current number of live threads including both daemon and non-daemon threads
# TYPE jvm_threads_live_threads gauge
jvm_threads_live_threads 35.0
# HELP http_server_bytes_read  
# TYPE http_server_bytes_read summary
http_server_bytes_read_count 1.0
http_server_bytes_read_sum 0.0
# HELP http_server_bytes_read_max  
# TYPE http_server_bytes_read_max gauge
http_server_bytes_read_max 0.0
# HELP jvm_memory_usage_after_gc_percent The percentage of old gen heap used after the last GC event, in the range [0..1]
# TYPE jvm_memory_usage_after_gc_percent gauge
jvm_memory_usage_after_gc_percent{area="heap",generation="old",} 0.0015022370123094128
# HELP system_cpu_count The number of processors available to the Java virtual machine
# TYPE system_cpu_count gauge
system_cpu_count 8.0

Prometeusでデータを取得する

Prometeus Pull型のモニタリングとアラートを行なうためのツールキットです。 Dockerで準備して、アプリのメトリクスを取得してみます。

prometheus.ymlを準備しておく

ここを参考にPrometheusの設定を記述します。
Dockerでボリュームマウントできれば、設定はどこでも良いのですが一旦/tmp/etc/prometheus.yamlに作成しました。

global:
  scrape_interval:     15s
  evaluation_interval: 15s

rule_files:

scrape_configs:
  - job_name: prometheus
    static_configs:
      - targets: ['${IP_OF_YOUR_APP}:8080']

注目すべきは-targetsのところで、ここにQuarkusあぷりのホストとポートを指定します。
アプリは/metricsで情報の公開を行っていますが、Prometheusはデフォルトで、/metricsに情報を取得しに行くためPathなどの指定は必要ありません。

docker runでPrometeusを起動する

以下のコマンドでPrometeusを起動します。
ボリュームのマウントはホスト側のyamlファイルを置いた場所に指定します。

docker run \
    -p 9090:9090 \
    -v /tmp/etc/prometheus.yaml:/etc/prometheus/prometheus.yml \
    prom/prometheus

PrometheusのUIを確認

起動してブラウザーから9090にアクセスしてみるとデータが取得できているのが確認できます。

f:id:yuya_hirooka:20201104222229p:plain

Grafanaで可視化する

Grafanaはメトリクスの可視化ツールです。 Prometheusなどで収集したデータに対してよりリッチなUIを提供したりできます。
こちらもDockerでさくっと立ち上げてみます。

docker run -d -p 3000:3000 grafana/grafana

http://localhost:3000/にアクセスすると、Login画面にリダイレクトされます。
初回パスワード/ユーザ名はadmin/adminです。

f:id:yuya_hirooka:20201104224941p:plain

Prometeusに接続する

Prometeusからメトリクスを収集するようにします。
右のメニューバーの歯車を選択し、add data sourceを選択すると以下のような画面が表示されます。

f:id:yuya_hirooka:20201104225231p:plain

ここでは迷うこと無くPrometheusを選択します。
すると以下の設定画面に遷移します。

f:id:yuya_hirooka:20201104225644p:plain

いろいろ設定項目がありますが、今回はただ動かしたいだけなので、Prometheusが動いているIPとポートをURLのとろこに設定します。同じやり方をされていればホストマシンのIPをここにかけば大丈夫です。

ダッシュボードを作成する

最後にダッシュボードを作成してみます。
また、右のメニューバーから+のボタンを押して、Dashbordを選択すると以下のような画面に遷移します。

f:id:yuya_hirooka:20201104230249p:plain

あとはお好きなようにメトリクスをしたり、クエリを書いたりしてお好みのダッシュボードを作っていく感じです。 画像では単にMetricsのところでjvm_gc_max_data_size_bytesを選択しただけです。

設定項目一覧

上記までで可視化は完了しましたが、Quarkusで設定できるMicrometerのプロパティをいくつかまとめておこうと思います。
すべてのプロパティを見たい方はこちらを参照ください(気が向いたら追記していくかもです)

プロパティ 説明 型(デフォルト値)
quarkus.micrometer.enabled Micromerterのサポートを有効化するフラグ boolean(true)
quarkus.micrometer.registry-enabled-default クラスパス内にMeterRegistryの実装を見つけた場合に自動的に認識するか否かを決めるためのフラグ。デフォルトでは自動的に認識する。 boolean(true)
quarkus.micrometer.binder-enabled-default クラスパス内にMeterBinderの実装を見つけた場合に自動的に認識するか否かを決めるためのフラグ。デフォルトでは自動的に認識する。 boolean(true)
quarkus.micrometer.binder.vertx.enabled Vert.xのメトリクスサポートの有効化フラグマイクロメータのサポートが有効化されている場合、Vert.xのMetricsOpitongaクラスパスにある場合、このプロパティにtrueが指定されている場合、quarkus.micrometer.binder-enabled-defaultがtrueの場合にtrueになる boolean
quarkus.micrometer.binder.mp-metrics.enabled MicroProfile Metricsのサポート有効化フラグ、 boolean
quarkus.micrometer.binder.jvm jvmのメトリクスサポートの有効化フラグ boolean(true)
quarkus.micrometer.binder.system システムのメトリクスサポート有効化フラグ boolean
quarkus.micrometer.export.prometheus.path メトリクスを公開するパスを指定するためのプロパティ string(/metrics)
quarkus.micrometer.export.json.enabled Jsonフォーマットでのメトリクス公開を行なうか否かのフラグ boolean(false)

参考資料