Graphite / Carbon の統計情報を読み解く

f:id:miyahan:20161116181011p:plain

Graphite の データ記録を担う Carbon には自身の統計情報を自身のデータベースに記録する機能があります。以前パフォーマンス問題の調査のためにこれを使ったのですが、各パラメーターが何を意味しているのか、ドキュメントを探したものの見つからず苦労しました。

そこで、記録された実データや、設定変更に伴う挙動から「たぶんこうだろう」と思うところをメモとして残しておきます。もしお役に立てば幸いです。また、公式ドキュメントのありかや有用な情報をご存じの方、誤りを見つけた場合はぜひコメントください。


Carbon statistics の設定

この機能はデフォルトでONになっているので、何をしなくてもすぐ使えます。ちなみに /etc/carbon/carbon.conf で明示的に設定することができます。

# By default, Carbon itself will log statistics (such as a count,
# metricsReceived) with the top level prefix of 'Carbon' at an interval of 60
# seconds. Set CARBON_METRIC_INTERVAL to 0 to disable instrumentation
CARBON_METRIC_PREFIX = carbon  # デフォルトでは carbon.**** のメトリックで記録される
CARBON_METRIC_INTERVAL = 60  # デフォルトでは60秒間隔で記録される

初期設定ではログを90日間保存するようになっています。これを変更する場合は /etc/carbon/storage-schema.conf を編集してからデータベースを再構築してください。

[carbon]
pattern = ^carbon\.
retentions = 60:90d

cpuUsage / memUsage

まあ文字通りCPUとメモリの使用量を示しているようです。しかし若干注意が必要です。

f:id:miyahan:20161117180237p:plain 図:CPUが100%に張り付いていたときのダッシュボード

上例では top コマンドでみるとずっと100%に張り付いていたのですが、cpuUsage だと 80%前後と値に差異がありました。単に誤差なのか、もしかすると carbon-cache プロセス全体ではなく、writerスレッド(データの書き込みを行うスレッド)のCPU使用率を示しているのかもしれません。

Carbon はマルチスレッドで動作していますが、Pythonグローバルインタプリタロックという制約によって、CPUチップ・コア数に対してスケールしません。すなわちCPU使用率がほぼ100%になっていたら、書き込み処理が滞留していないか確認が必要です。

avgUpdateTime

ディスクへの書き込みに要した時間(おそらくms)を示していると思います。ディスクの性能や、一度に書き込むデータポイント量に左右されます。

f:id:miyahan:20161117184058p:plainf:id:miyahan:20161117184101p:plain f:id:miyahan:20161117184110p:plainf:id:miyahan:20161117184114p:plain

やはり HDD と SSD ではまさに桁違いですね。特に HDD ではログローテーションなど、I/Oを伴うバックグラウンド処理が走ったものなら、さらにズドンと跳ね上がります。

このパラメーターはディスクの状態を把握することはできますが、Carbon の状態を確認するにはあまり使えないでしょう。「ああ、HDDさんキツそうだな・・・」くらいに見ておきましょう。

metricsReceived / committedPoints

これらはデータの IN と OUT を表すパラメーターです。metricsReceived は Carbon が受信したデータポイント量committedPoints はディスクへ書き込んだデータポイント量を示しているようです。つまりフィルタで記録するデータを絞り込んでいない限り、下図のように中期的に見て この2つのパラメーターは概ねイコールになっていなければなりません。

f:id:miyahan:20161117190452p:plain

なおこれらのパラメーターは前回の測定(デフォルトで60秒前)からの増分を記録しているようなので、このダッシュボードでは 1/60 = scale(0.1667) して毎秒値に換算しています。

updateOperations / pointsPerUpdate

これらはディスクへの書き込みに関連するパラメーターです。updateOperations はディスクへ書き込んだ回数を示しているようです。これも増分値ですのでダッシュボード上は 1/60 して毎秒値に換算しています。一方、pointsPerUpdate は1回のディスクフラッシュで書き込んだデータポイント量を示しているようです。

すなわち、updateOperations[回] × pointsPerUpdate[データポイント/回] ≒ committedPoints[データポイント] という関係が成り立ちます。ダッシュボードでも確かめてみましょう。

f:id:miyahan:20161117194604p:plain 図:MAX_UPDATES_PER_SECOND = inf

まずは書き込み頻度を無制限にした場合。受信したデータはその都度即時ディスクにフラッシュされているため、metricsReceived ≒ updateOperations ≒ committedPoints ≒ 6000 となっています。1回の受信で1回書き込んでいるため、pointsPerUpdate は 1 となります。

f:id:miyahan:20161117202510p:plain 図:MAX_UPDATES_PER_SECOND = 3000

次に書き込み頻度をトラフィックのおよそ半分、3000回/秒に設定した場合。ディスクフラッシュの頻度(updateOperations) が3000回/秒になっていますね。また pointsPerUpdate より1回のディスクフラッシュで平均2個のデータポイントを書き込んでいることがわかります。3000回/秒 × 2データポイント/回 = 6000データポイント/秒 となるわけです。

実際にこれらのパラメーターがどのような比になるかは、設定やディスクのI/O性能に左右されます。

cache.queues / cache.size

今度はメモリキャッシュに関するパラメーターです。これは Carbon の書き込み状況を知るために最も役立つものです。cache.queues はメモリキャッシュに入っているメトリックの数、cache.size はメモリキャッシュに入っているデータポイントの数を示しているようです。これに気づくまでずいぶん苦労しました・・・。

00:00 もも組.うさぎさん 30
00:00 みかん組.くまさん 5
00:01 もも組.うさぎさん 15
00:01 みかん組.くまさん 7
00:02 もも組.うさぎさん 40
00:02 みかん組.くまさん 9
00:03 もも組.うさぎさん 20
00:03 みかん組.くまさん 6
00:04 もも組.うさぎさん 25
00:04 みかん組.くまさん 8
00:05 もも組.うさぎさん 30
00:05 みかん組.くまさん 7
00:06 もも組.うさぎさん 35
00:06 みかん組.くまさん 11
00:07 もも組.うさぎさん 40
00:07 みかん組.くまさん 9
00:08 もも組.うさぎさん 35
00:08 みかん組.くまさん 10
00:09 もも組.うさぎさん 30
00:09 みかん組.くまさん 8

例えば上記のデータがキャッシュに入った場合、メトリックは "もも組.うさぎさん" と "みかん組.くまさん" の2種類だけなので cache.queues は 2、データポイントは20個あるので cache.size は 20 となります。

f:id:miyahan:20161117214916p:plain 図:ディスクへの書き込みが間に合わず、どんどんキャッシュサイズが増大している事例

記録するメトリックは予め決まっている場合が多いので、どんなに多くのトラフィックが突っ込んできても cache.queues はある決まった値で頭打ちとなりますが、cache.size はディスクフラッシュが追いつかない場合、無限に増大していきます。つまり、cache.size こそが Carbon のI/O負荷監視の最重要パラメーターと言えます。これが増加していたらヤバい!!

cache.queries

これまでパラメーターとは違って、cache.queries はデータを読み込む頻度を示しています。Grafana でダッシュボードの再読み込みボタンを連打するとこの値が増加します。これも増分値ですのでダッシュボード上は 1/60 して毎秒値に換算しています。

ところで Graphite はクエリを受けると、ディスクにあるデータ(Whisperデータベース) を読み込みつつ、Carbon がメモリに保持しているフラッシュ待ちのキャッシュも読み込み、それらをマージしてクライアントに返答しています。名前から察するに、cache.queries は厳密に言えば、Graphite が Carbon のキャッシュに問い合わせた回数を記録しているのかもしれません。


いかがでしたでしょうか。大量のデータを Graphite で記録している方で、ときどきデータが記録されなくなったり表示されなくなったりする、プロセスを再起動したらなぜか半日分のデータが吹っ飛んだ、といったトラブルが起きた場合は、ぜひ Carbon の統計情報を見てオーバーロードが発生していないかチェックしてみてください。