Mac 10.8にrbenv+ruby-buildでRuby 1.9系にしてfluentdをインストールして試してみる
最近fluentdに触れる機会ができましたので備忘録としてブログに書いてみたいと思います。
fluentdタグでブログを書くのは↓以来1年振り2回目になります。
fluentdを試してみた - wyukawa’s blog
まずは環境構築です。fluentdはRuby 1.9系が前提なのですがMacにはRuby 1.8系しかないですよね。
Ruby弱者なのでよくわからないですが、こういうときはrvmかrbenvを使うみたいです。pythonでいうとpythonbrew的なもんだと思います。
rbenv+ruby-buildのほうがイマドキらしいのでこっちを使ってみます。
rbenv+ruby-buildのインストール
$ brew install rbenv ruby-build $ echo 'eval "$(rbenv init -)"' >> ~/.bashrc
Ruby 1.9.3-p327をインストール
$ rbenv install 1.9.3-p327 $ rbenv rehash $ rbenv local 1.9.3-p327
fluentdのインストール。今回試したのは0.10.31です。
$ gem install fluentd $ rbenv rehash
fluentdのヘルプ
$ fluentd -h Usage: fluentd [options] -s, --setup [DIR=/etc/fluent] install sample configuration file to the directory -c, --config PATH config file path (default: /etc/fluent/fluent.conf) -p, --plugin DIR add plugin directory -I PATH add library path -r NAME load library -d, --daemon PIDFILE daemonize fluent process --user USER change user --group GROUP change group -o, --log PATH log file path -i CONFIG_STRING, inline config which is appended to the config file on-fly --inline-config -v, --verbose increase verbose level (-v: debug, -vv: trace) -q, --quiet decrease verbose level (-q: warn, -qq: error)
fluentdの設定ファイル生成
$ fluentd --setup ./fluent
fluentdの起動
$ fluentd -c ./fluent/fluent.conf -vv
ちなみにプロセスは2個立ち上がります。
$ ps -ef | grep fluent\[d\] 502 35232 2164 0 12:00AM ttys001 0:00.19 /Users/wyukawa/.rbenv/versions/1.9.3-p327/bin/ruby /Users/wyukawa/.rbenv/versions/1.9.3-p327/bin/fluentd -c ./fluent/fluent.conf -vv 502 35261 35232 0 12:00AM ttys001 0:00.08 /Users/wyukawa/.rbenv/versions/1.9.3-p327/bin/ruby /Users/wyukawa/.rbenv/versions/1.9.3-p327/bin/fluentd -c ./fluent/fluent.conf -vv
生成したfluent.confのうちコメントアウトされていない箇所を抜き出すとこんな感じになってます。今回使わないDRbの部分を除いて書くとTCP(24224), HTTP(8888) の入力を受けつけ、debug.** というタグを持ったメッセージを標準出力に出力するように設定されています。
## built-in TCP input ## $ echo <json> | fluent-cat <tag> <source> type forward </source> # HTTP input # http://localhost:8888/<tag>?json=<json> <source> type http port 8888 </source> # Listen DRb for debug <source> type debug_agent port 24230 </source> ## match tag=debug.** and dump to console <match debug.**> type stdout </match>
fluentdを起動したものとは別のシェルから下記のようにコマンドを実行します。
echo '{"json":"message"}' | fluent-cat debug.test
するとfluentdを起動したシェルの標準出力に下記のように出力されると思います。debug.testタグがdebug.**にマッチしたので標準出力に出力されました。
2013-02-11 22:51:06 +0900 debug.test: {"json":"message"}
fluentdはinput→buffer→outputというプラグイン構造をしています。
今回使ったのはin_forwardプラグインとout_stdoutプラグインですね。どちらも標準で入っています。
in_httpプラグインを試すために下記のようにcurlコマンドでhttpリクエストを送ります。
curl -X POST -d 'json={"action":"login","user":2}' http://localhost:8888/debug.http
すると下記のように出力されます。
2013-02-11 22:58:40 +0900 debug.http: {"action":"login","user":2}
次はRubyのアプリからログ出力してみましょう。
fluent-loggerをインストールします。
$ gem install fluent-logger
そしてこんな感じのRubyソースを書いて実行します。
require 'fluent-logger' Fluent::Logger::FluentLogger.open(nil, host: 'localhost', port: 24224) Fluent::Logger.post('debug.ruby', { hoge: 'fuga', foo: 'bar' })
実行結果はこんな感じになります。
2013-02-11 23:02:40 +0900 debug.ruby: {"hoge":"fuga","foo":"bar"}
さてここまでの内容だと以下の記事をrvmじゃなくてrbenvを使って書き換えただけになってしまいますので(汗 もうちょっと書きたいと思います。
Mac OS X に Fluentd をインストールして Ruby からログ出力してみる
fluentdを使っているとbuffer溢れがおこることがあります。このときログに「queue size exceeds limit」と出力されます。
fluentdのbufferはchunkという単位でキューイングされます。
chunk1 | chunk2 | chunk3 | ... |
設定ファイルで指定するbuffer_chunk_limitは1つのchunkのデータサイズでbuffer_queue_limitはchunkの数になります。
fluentdのinputプラグインはマルチスレッドで動作しどんどんbufferにキューイングするのでIO処理でブロックされてキューイングに詰まるということはないと思います。たぶん。
一方でoutputプラグインへの出力が詰まっているとbuffer溢れがおこります。
ちょっとbuffer溢れを再現させてみますね。例えばbuffering機能を使うout_fileで以下のように設定します。
<match file.**> type file path /tmp/hoge buffer_chunk_limit 1k buffer_queue_limit 1 </match>
そんでもって以下のようにして10000リクエストを並行でなげます。
for i in `seq 1 10000` do curl -X POST -d 'json={"hoge":"fuga"}' http://localhost:8888/file.http & done
そうすると以下のようにbuffer溢れがおきます。
fluent/engine.rb:122:rescue in emit_stream: emit transaction failed error="queue size exceeds limit" fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/fluentd-0.10.31/lib/fluent/buffer.rb:180:in `block in emit' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/1.9.1/monitor.rb:211:in `mon_synchronize' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/fluentd-0.10.31/lib/fluent/buffer.rb:166:in `emit' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/fluentd-0.10.31/lib/fluent/output.rb:506:in `block in emit' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/fluentd-0.10.31/lib/fluent/event.rb:52:in `call' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/fluentd-0.10.31/lib/fluent/event.rb:52:in `each' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/fluentd-0.10.31/lib/fluent/output.rb:496:in `emit' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/fluentd-0.10.31/lib/fluent/match.rb:38:in `emit' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/fluentd-0.10.31/lib/fluent/engine.rb:120:in `emit_stream' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/fluentd-0.10.31/lib/fluent/engine.rb:101:in `emit' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/fluentd-0.10.31/lib/fluent/plugin/in_http.rb:132:in `on_request' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/fluentd-0.10.31/lib/fluent/plugin/in_http.rb:249:in `call' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/fluentd-0.10.31/lib/fluent/plugin/in_http.rb:249:in `on_message_complete' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/fluentd-0.10.31/lib/fluent/plugin/in_http.rb:169:in `<<' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/fluentd-0.10.31/lib/fluent/plugin/in_http.rb:169:in `on_read' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/cool.io-1.1.0/lib/cool.io/io.rb:108:in `on_readable' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/cool.io-1.1.0/lib/cool.io/io.rb:170:in `on_readable' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/cool.io-1.1.0/lib/cool.io/loop.rb:96:in `run_once' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/cool.io-1.1.0/lib/cool.io/loop.rb:96:in `run' fluent/engine.rb:123:rescue in emit_stream: /Users/wyukawa/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/fluentd-0.10.31/lib/fluent/plugin/in_http.rb:99:in `run'
out_fileじゃないですが僕もbuffer溢れに遭遇しました。で、この手のbuffer溢れ問題はfluentdを複数起動して回避するのが一つの手のようですね。もちろん複数CPUでCPUが余っていることが前提です。もしかしたらout_forwardをマルチスレッドで動かすようにしてoutput詰まりを回避するという方法もあるかもしれませんがこっちは試していませんね。
以下本論とはあまり関係ないですがRuby/Python弱者の独り言です。
RubyはGiant VM lock (GVL) をもっていて同時に実行される ネイティブスレッドは常にひとつなのでスレッドを有効に使えるのってIOが絡む箇所ぐらいなのかなあと思ったりしてます。なのでマルチスレッドよりはマルチプロセスなのかなと。PythonもGIL(Global Interpreter Lock) を持っていてRubyと似たような状況ですよね。この辺はPython2.6 で実装されたmultiprocessing パッケージあたりが関係してくるのかなと。multiprocessingはfabricが確か使ってましたよね。