Webサーバの仮想ホスト単位のリソース使用量をFluentd+Norikra+GrowthForecastでグラフ化

ご存知の通り、ApacheのVirtualHost（以下vhost）、所謂、Webサーバの仮想ホストは単一のApacheで複数のホストを処理しています。そのため、複数のvhostを含めたCPU使用量といったリソース使用量をグラフ化することは簡単なのですが、vhost単位となると各vhostへのリクエスト単位でのリソースを計測しておかないとグラフ化することはできません。そういう意味でvhost単位でリソース使用量をグラフ化しようとすると一気に敷居が上がってしまいます。

また、uid毎に実行プロセスを分離しておけば、pacctといったプロセスアカウンティング機能でuidのカウントはできますが、リアルタイムの計測（秒とか分のオーダー）にはコストが高かったり、vhostで提供しているコンテンツによっては、Apache権限で配信されているものもある（静的コンテンツ）ため、正確に計測することは難しくなります。

一方で、ログをリアルタイムで集計して一定期間内で計測してグラフ化するツールとしては、FluentdやNorikra、GrowthForecastといった素晴らしいプロダクトがすでにあり、それらをうまく組み合わせてこれを実現したいという欲求が膨れ上がってきました。そう考えると、リクエスト単位でリソースを計測できれば、すぐに実装できそうです。

というわけで、思いついたらまずは手を動かしてみようということで、プロトタイプ実装をしてみました。

実装

大昔に作っていたリクエスト単位のリソース使用量を計測するためのApacheモジュールmod_resource_checkerを今風に改善して、リクエスト単位でリクエストに関する情報やリソース使用量をJSONにまとめてログに吐き出すようにしました。リクエスト単位でテキストファイル的には1行のJSONが吐き出されるので、以下のようにロギングされます。

{ "module": "mod_resource_checker", "date": "Tue Oct 13 21:04:10 2015", "type": "RCheckALL", "unit": null, "location": "\/", "remote_ip": "127.0.0.1", "filename": "\/usr\/local\/apache\/htdocs\/blog\/files\
/IMG_3122.JPG", "scheme": "http", "method": "GET", "hostname": "blog.matsumoto-r.jp", "server_ip": "127.0.0.1", "uri": "\/files\/IMG_3122.JPG", "real_server_name": "www.matsumoto-r.jp", "uid": 2, "size": 50
947, "content_length": 50947, "status": 200, "pid": 23373, "threshold": null, "response_time": 0.000000, "result": { "RCheckUCPU": 0.002000, "RCheckSCPU": 0.000000, "RCheckMEM": 0.050781 } }
{ "module": "mod_resource_checker", "date": "Tue Oct 13 21:04:11 2015", "type": "RCheckALL", "unit": null, "location": "\/", "remote_ip": "153.215.184.86", "filename": "\/usr\/local\/apache\/htdocs\/blog\/w
p-content\/themes\/wp.vicuna.exc\/style.php", "scheme": "http", "method": "GET", "hostname": "blog.matsumoto-r.jp", "server_ip": "127.0.0.1", "uri": "\/wp-content\/themes\/wp.vicuna.exc\/style.php", "real_s
erver_name": "www.matsumoto-r.jp", "uid": 2, "size": 405, "content_length": 55, "status": 200, "pid": 23373, "threshold": null, "response_time": 0.000000, "result": { "RCheckUCPU": 0.288956, "RCheckSCPU": 0
.045993, "RCheckMEM": 5.070312 } }

jqを使って整形するとこんな感じです。

{
  "result": {
    "RCheckMEM": 0.050781,
    "RCheckSCPU": 0,
    "RCheckUCPU": 0.002
  },
  "response_time": 0,
  "threshold": null,
  "pid": 23373,
  "status": 200,
  "scheme": "http",
  "filename": "/usr/local/apache/htdocs/blog/files/IMG_3122.JPG",
  "remote_ip": "127.0.0.1",
  "location": "/",
  "unit": null,
  "type": "RCheckALL",
  "date": "Tue Oct 13 21:04:10 2015",
  "module": "mod_resource_checker",
  "method": "GET",
  "hostname": "blog.matsumoto-r.jp",
  "server_ip": "127.0.0.1",
  "uri": "/files/IMG_3122.JPG",
  "real_server_name": "www.matsumoto-r.jp",
  "uid": 2,
  "size": 50947,
  "content_length": 50947
}
{
  "result": {
    "RCheckMEM": 5.070312,
    "RCheckSCPU": 0.045993,
    "RCheckUCPU": 0.288956
  },
  "response_time": 0,
  "threshold": null,
  "pid": 23373,
  "status": 200,
  "scheme": "http",
  "filename": "/usr/local/apache/htdocs/blog/wp-content/themes/wp.vicuna.exc/style.php",
  "remote_ip": "153.215.184.86",
  "location": "/",
  "unit": null,
  "type": "RCheckALL",
  "date": "Tue Oct 13 21:04:11 2015",
  "module": "mod_resource_checker",
  "method": "GET",
  "hostname": "blog.matsumoto-r.jp",
  "server_ip": "127.0.0.1",
  "uri": "/wp-content/themes/wp.vicuna.exc/style.php",
  "real_server_name": "www.matsumoto-r.jp",
  "uid": 2,
  "size": 405,
  "content_length": 55
}

さらに、これをFluentdで集約し、Norikraを使って1分間のログからデータを計測して、結果をGrowthForecastでグラフ化するようにしました。

td-agentの設定は以下のようになります。まだ触り始めたばかりなのでtagでゴニョニョするあたりとかきっちりとはよくわかっていませんが、そこは今後リファクタしていくとして以下のような設定でとりあえず無事動きました。

実装後にlabelの存在を知ったり、なんか色々遅れてる感がすごいですが、この辺どんどん触って追いついていきたいです。

# from mod_resource_checker log
<source>
  type tail
  path /var/log/httpd/resource.log
  pos_file /var/log/td-agent/resource.log.pos
  tag apache.resource
  format json
</source>

# into Norikra
<match apache.resource.**>
  type     norikra
  norikra  127.0.0.1:26571

  remove_tag_prefix apache
  target_map_tag     true
</match>

# from Norikra
<source>
  type    norikra
  norikra 127.0.0.1:26571
  <fetch>
    method sweep
    tag_prefix norikra.query
    tag query_name
    interval 1m
  </fetch>
</source>

# tagging vhost 
<match norikra.query.**>
  type rewrite_tag_filter
  rewriterule1 hostname (.+) hostname.${tag}.$1
</match>

# for status code graph
<match hostname.norikra.query.status.**>
  type forest
  subtype growthforecast
  remove_prefix hostname.norikra.query.status

  <template>
    gfapi_url http://127.0.0.1:5125/api/
    graph_path ${tag}/apache/${key_name}
    name_keys count_2xx,count_3xx,count_4xx,count_5xx
  </template>
</match>

# for resource graph
<match hostname.norikra.query.resources.**>
  type forest
  subtype growthforecast
  remove_prefix hostname.norikra.query.resources

  <template>
    gfapi_url http://127.0.0.1:5125/api/
    graph_path ${tag}/apache/${key_name}
    name_keys ucpu,scpu,memory,total_size,total_content_length
  </template>
</match>

# for custom response graph
<match hostname.norikra.query.**>
  type forest
  subtype growthforecast
  remove_prefix hostname.norikra.query

  <template>
    gfapi_url http://127.0.0.1:5125/api/
    graph_path ${tag_parts[1..-1]}/apache/${tag_parts[0]}
    name_keys res
  </template>
</match>

こうやってfluentdに集約したログをnorikra側で以下のようなSQLにより特定の時間間隔で集計します。

• name:resources, group:(default)

SELECT
    hostname,
    SUM(result.RCheckUCPU) as ucpu,
    SUM(result.RCheckSCPU) as scpu,
    SUM(result.RCheckMEM) as memory,
    SUM(size) as total_size,
    SUM(content_length) as total_content_length
  FROM resource.win:time_batch(1 min)
  WHERE type='RCheckALL'
  GROUP BY hostname

このSQLにより、vhost単位でのリソース使用量や転送量の1分間の合計を計測します。

• name:response_time, group:(default)

SELECT
    hostname,
    SUM(response_time) / COUNT(*) as res
  FROM resource.win:time_batch(1 min)
  WHERE type='RCheckALL'
  GROUP BY hostname

このSQLは、vhost単位での1分間でのレスポンスタイムの平均値を計測します。

• name:status, group:(default)

SELECT
    hostname,
    COUNT(1, status REGEXP '^2..$') as count_2xx,
    COUNT(1, status REGEXP '^3..$') as count_3xx,
    COUNT(1, status REGEXP '^4..$') as count_4xx,
    COUNT(1, status REGEXP '^5..$') as count_5xx
  FROM resource.win:time_batch(1 min)
  WHERE type='RCheckALL'
  GROUP BY hostname

このSQLは、1分間でのそれぞれのstatusコードの合計数を計測します。

で、これをFluentd上でNorikra側から得られたvhost名をtagに変換して分類し、Norikraのquery_nameやカラム名を元にGrowthForecastにデータを動的に送信してグラフ化します。

その結果、vhost単位でのリソース使用量やレスポンスタイム、statusコードの集計、転送量といった値が高いリアルタイム性（1時間毎の計測ではなく秒や分のオーダー）で簡単にグラフ化できました。

vhost単位で、かつ、リアルタイム性の高いグラフ生成がこんな簡単に構造化できて動的に実装できるのはヤバイですね。Fluentd+Norikra+GrowthForecastは本当に便利だと思います。

以下のようにvhostが増えるたびにvhostのグラフが作成され、

vhost単位で以下のようにリソースグラフが作成されています。

一つのApacheで管理しているvhostを、vhostに紐づく固有の設定をすることもなく、また、新たなvhost設定がApacheに追加されても、mod_resource_checkerのログが出力された段階で自動でvhost単位のグラフが作成できるようになりました。便利！！

今後、vhostを管理しているサーバが増えても、Fluentdに適切にログを送ってやりさえすれば自動的にどんどんグラフが作られていきます。とはいえ、各コンポーネントのオーバーヘッドや収容設計を見直す必要はもちろんありますが。

まとめ

ということで、今回はプロトタイプ実装として、vhost単位で、vhost固有の設定をすることなくvhostのリソース使用量をグラフ化する事ができました。

しかもこれ、postfixとかdovecotとかapacheとかnginxとかMySQLとかなんかいろいろ動きまくってるメモリ2GBのCPU2コアの環境で全部入れても問題なく動いているんですよね。すごいなぁ。

今後は1サーバにvhostが10000ぐらい収容されていて、そのサーバが100のオーダーであるようなより大規模な環境において、いかに効率よくグラフ化する設定やログ計測の設定をするかについて、各コンポーネントの設計を考えていきたいと思います。

今のところ、上記の環境でやろうとすると、グラフ化する際のリクエスト数が理論値ではすごい値になってしまったり、グラフのサービスやセクションのまとめ方も工夫しないと表示がすごいことになったりするので、その辺りを中心に全体を見直していく予定です。

また、norikraでやりたい事が増えたりした時にもそれに耐えうるようにハードウェアの収容設計といったあたりも検討していきたいです。