ruby 2.1.0-preview1 を fluentd で試してみた (追記あり) (再度追記あり)
2.1.0-preview1 が出た。RGenGCはそのロジックがいかにもFluentdにジャストフィットしそうなので期待していた。あとGCまわりも含めあれこれ変わってるので、使うと事故るなら早めに確認しておこうかな、という感じ。
確認したノードは以下の2種類で1台ずつ。
- fluentd + out_exec_filter (+perlの外部プロセス) でログをparseするworker
- fluentd で大量のクライアント(fluent-agent-liteなど)から接続を受け付け、fluentdクラスタの各ノードへロードバランスするdeliver
で、本日の12:40くらいに変更したと思いねえ。そのグラフがこれ。トラフィック、CPU使用率、メモリ使用量。
結論
なんか問題がありそうなので直るのを待ちたい。これが直ったという話があるまで 2.1.x は厳しいなあ。
本当は自分であれこれ調査すべきなんだけど、ちょっと他にも手元の作業があれこれあるので必要なら後から……。誰かこれとこれを調べろ！ と指定してくださると調査がしやすいですが。
追記(9/26)
hsbtさんから助言をいただいたので試してみました。メモリ使用量の増大が見られたworkerでの結果です。
@tagomoris 再コンパイルが必要でちょっとだるいのですが、RGenGC を切って試すと特定範囲を狭めることが出来ます。 URL
2013-09-26 09:09:21 via web to @tagomoris
@meskyanichi Thank you for your report. could you try without gengc (turn 0 the macro USE_RGENGC in include/ruby/ruby.h)?
2013-09-25 12:26:01 via web to @meskyanichi
以下のグラフで16:30頃に ruby 2.1.0-preview1 w/o RGenGC なものに入れ替えてます。
結果として RGenGC を切ったものを再ビルドして試したところメモリ使用量の急激な増大は見られず、おおむね問題のない状況になってます。載せてませんがCPU使用率も 2.0.0 と変わらず。
ふーむ。
再度追記(9/27)
そのまま翌朝まで動かしてみたらやっぱりダメっぽい感じでした……。 Ruby 2.1.0-preview1 without RGenGC on worker node。
まあ RGenGC にたぶん問題があって、それ以外にもなんかありそうだね、という感じです。
Fluentd側のログはこんなで、どうにもならなくてFluentd supervisor processから SIGKILL だけですね。べつにバッファが食ってるとかいうわけじゃない*1
2013-09-26 19:37:06 +0900 [info]: out_forest plants new output: sampling_filter for tag '....'
2013-09-27 06:34:33 +0900 [info]: process finished code=9
2013-09-27 06:34:33 +0900 [error]: fluentd main process died unexpectedly. restarting.
2013-09-27 06:34:33 +0900 [info]: starting fluentd-0.10.39
2013-09-27 06:34:33 +0900 [info]: reading config file path="run/serializer.conf"
2013-09-27 06:34:34 +0900 [info]: using configuration file: <ROOT>
<source>
type forward
....なおメモリを食ってるのはこのノード上にある serializer プロセス*2のみで、workerプロセス*3では同じ問題は起きてないようです。きっかけは今のところ不明。
### ps axuww の結果 # これがserializer username 24191 0.0 0.0 119020 2536 ? Sl Sep26 0:00 ruby /home/username/local/ruby-2.1.0pre1patched/bin/fluentd -c run/serializer.conf --emit-error-log-interval 60 username 15219 21.7 45.0 11071856 7338252 ? Sl 06:34 71:28 ruby /home/username/local/ruby-2.1.0pre1patched/bin/fluentd -c run/serializer.conf --emit-error-log-interval 60 # こっちは worker ひとセット username 23743 0.0 0.0 118960 1716 ? Sl Sep26 0:00 ruby /home/username/local/ruby-2.1.0pre1patched/bin/fluentd -c run/worker.24211.conf --emit-error-log-interval 60 username 23746 7.1 0.5 914992 89708 ? Sl Sep26 83:20 ruby /home/username/local/ruby-2.1.0pre1patched/bin/fluentd -c run/worker.24211.conf --emit-error-log-interval 60 username 23757 11.7 0.0 36956 3488 ? S Sep26 137:29 perl -Iextlib/lib/perl5 -Ilib /home/username/secret_log_converter/bin/convert.pl
ロングランで分かることというのもあるなあ。
